Re: [PATCH v5 22/22] sound/usb: Use Media Controller API to share media resources

[Mauro Carvalho Chehab <mchehab@osg.samsung.com>]

Em Wed,  2 Mar 2016 09:50:31 -0700
Shuah Khan <shuahkh@osg.samsung.com> escreveu:

> Change ALSA driver to use Media Controller API to
> share media resources with DVB and V4L2 drivers
> on a AU0828 media device. Media Controller specific
> initialization is done after sound card is registered.
> ALSA creates Media interface and entity function graph
> nodes for Control, Mixer, PCM Playback, and PCM Capture
> devices.
> 
> snd_usb_hw_params() will call Media Controller enable
> source handler interface to request the media resource.
> If resource request is granted, it will release it from
> snd_usb_hw_free(). If resource is busy, -EBUSY is returned.
> 
> Media specific cleanup is done in usb_audio_disconnect().
> 
> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
> Acked-by: Takashi Iwai <tiwai@suse.de>

Shuah, by looking at the produced graphs:
	https://mchehab.fedorapeople.org/mc-next-gen/au0828_test/

I'm noticing the lack of ALSA I/O entities in the diagram
(MEDIA_ENT_F_AUDIO_CAPTURE). The mixer there is not connected.

Could you please check what's happening?

Those are the relevant dmesg data:

[   19.017276] usbcore: registered new interface driver snd-usb-audio
[  230.706102] Linux video capture interface: v2.00
[  230.856983] au0828: au0828 driver loaded
[  231.230612] au0828: i2c bus registered
[  231.822006] tveeprom 5-0050: Hauppauge model 72001, rev E1H3, serial# 4035199481
[  231.822991] tveeprom 5-0050: MAC address is 00:0d:fe:84:41:f9
[  231.823955] tveeprom 5-0050: tuner model is Xceive XC5000C (idx 173, type 88)
[  231.824782] tveeprom 5-0050: TV standards NTSC(M) ATSC/DVB Digital (eeprom 0x88)
[  231.825272] tveeprom 5-0050: audio processor is AU8522 (idx 44)
[  231.825276] tveeprom 5-0050: decoder processor is AU8522 (idx 42)
[  231.825280] tveeprom 5-0050: has no radio, has IR receiver, has no IR transmitter
[  231.825283] au0828: hauppauge_eeprom: hauppauge eeprom: model=72001
[  231.857567] au8522 5-0047: creating new instance
[  231.857879] au8522_decoder creating new instance...
[  231.910525] tuner 5-0061: Setting mode_mask to 0x06
[  231.910532] tuner 5-0061: tuner 0x61: Tuner type absent
[  231.910535] tuner 5-0061: Tuner -1 found with type(s) Radio TV.
[  231.911343] tuner 5-0061: Calling set_type_addr for type=88, addr=0x61, mode=0x04, config=ffffffffa0e64100
[  231.911347] tuner 5-0061: defining GPIO callback
[  231.934896] xc5000 5-0061: creating new instance
[  231.954664] xc5000: Successfully identified at address 0x61
[  231.954987] xc5000: Firmware has not been loaded previously
[  231.955327] tuner 5-0061: type set to Xceive XC5000
[  231.955330] tuner 5-0061: au0828 tuner I2C addr 0xc2 with type 88 used for 0x04
[  233.622614] au8522 5-0047: attaching existing instance
[  233.636061] xc5000 5-0061: attaching existing instance
[  233.645775] xc5000: Successfully identified at address 0x61
[  233.646034] xc5000: Firmware has not been loaded previously
[  233.646461] DVB: registering new adapter (au0828)
[  233.647575] usb 2-3.3: DVB: registering adapter 0 frontend 0 (Auvitek AU8522 QAM/8VSB Frontend)...
[  233.648344] dvb_create_media_entity: media entity 'Auvitek AU8522 QAM/8VSB Frontend' registered.
[  233.656105] dvb_create_media_entity: media entity 'dvb-demux' registered.
[  234.166644] IR keymap rc-hauppauge not found
[  234.166962] Registered IR keymap rc-empty
[  234.178055] input: au0828 IR (Hauppauge HVR950Q) as /devices/pci0000:00/0000:00:14.0/usb2/2-3/2-3.3/rc/rc0/input14
[  234.203311] rc rc0: au0828 IR (Hauppauge HVR950Q) as /devices/pci0000:00/0000:00:14.0/usb2/2-3/2-3.3/rc/rc0
[  234.207828] au0828: Remote controller au0828 IR (Hauppauge HVR950Q) initalized
[  234.208270] au0828: Registered device AU0828 [Hauppauge HVR950Q]
[  234.212073] usbcore: registered new interface driver au0828
[  234.230371] lirc_dev: IR Remote Control driver registered, major 243 
[  234.257555] rc rc0: lirc_dev: driver ir-lirc-codec (au0828-input) registered at minor = 0
[  234.257960] IR LIRC bridge handler initialized

(as au0828 is blacklisted, snd-usb-audio was probed first)

====xxxx====

I'm also getting some other weird behavior when removing/reinserting
the modules a few times. OK, officially we don't support it, but,
as devices can be bind/unbind all the times, removing modules is
a way to simulate such things. Also, I use it a lot while testing
USB drivers ;)

This one is after removing both the media drivers and snd-usb-audio, 
and then modprobing snd-usb-audio:

[ 1839.510587] BUG: sleeping function called from invalid context at mm/slub.c:1289
[ 1839.510881] in_atomic(): 1, irqs_disabled(): 0, pid: 3479, name: modprobe
[ 1839.511157] 4 locks held by modprobe/3479:
[ 1839.511415]  #0:  (&dev->mutex){......}, at: [<ffffffff81ce8933>] __driver_attach+0xa3/0x160
[ 1839.512381]  #1:  (&dev->mutex){......}, at: [<ffffffff81ce8941>] __driver_attach+0xb1/0x160
[ 1839.512388]  #2:  (register_mutex#5){+.+.+.}, at: [<ffffffffa10596c7>] usb_audio_probe+0x257/0x1c90 [snd_usb_audio]
[ 1839.512401]  #3:  (&(&mdev->lock)->rlock){+.+.+.}, at: [<ffffffffa0e6051b>] media_device_register_entity+0x1cb/0x700 [media]
[ 1839.512412] CPU: 2 PID: 3479 Comm: modprobe Not tainted 4.5.0-rc3+ #49
[ 1839.512415] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
[ 1839.512417]  0000000000000000 ffff8803b3f6f288 ffffffff81933901 ffff8803c4bae000
[ 1839.512422]  ffff8803c4bae5c8 ffff8803b3f6f2b0 ffffffff811c6af5 ffff8803c4bae000
[ 1839.512427]  ffffffff8285d7f6 0000000000000509 ffff8803b3f6f2f0 ffffffff811c6ce5
[ 1839.512432] Call Trace:
[ 1839.512436]  [<ffffffff81933901>] dump_stack+0x85/0xc4
[ 1839.512440]  [<ffffffff811c6af5>] ___might_sleep+0x245/0x3a0
[ 1839.512443]  [<ffffffff811c6ce5>] __might_sleep+0x95/0x1a0
[ 1839.512446]  [<ffffffff8155aade>] kmem_cache_alloc_trace+0x20e/0x300
[ 1839.512451]  [<ffffffffa0e66e3d>] ? media_add_link+0x4d/0x140 [media]
[ 1839.512455]  [<ffffffffa0e66e3d>] media_add_link+0x4d/0x140 [media]
[ 1839.512459]  [<ffffffffa0e69931>] media_create_pad_link+0xa1/0x600 [media]
[ 1839.512463]  [<ffffffffa0fe11b3>] au0828_media_graph_notify+0x173/0x360 [au0828]
[ 1839.512467]  [<ffffffffa0e68a6a>] ? media_gobj_create+0x1ba/0x480 [media]
[ 1839.512471]  [<ffffffffa0e606fb>] media_device_register_entity+0x3ab/0x700 [media]
[ 1839.512475]  [<ffffffffa0e60350>] ? media_device_release_devres+0x10/0x10 [media]
[ 1839.512479]  [<ffffffff8124068d>] ? trace_hardirqs_on+0xd/0x10
[ 1839.512482]  [<ffffffff8159f992>] ? create_object+0x5a2/0x940
[ 1839.512485]  [<ffffffff8159f3f0>] ? kmemleak_disable+0x90/0x90
[ 1839.512489]  [<ffffffff8159f3f0>] ? kmemleak_disable+0x90/0x90
[ 1839.512497]  [<ffffffffa109722c>] ? media_snd_mixer_init+0x16c/0x500 [snd_usb_audio]
[ 1839.512501]  [<ffffffff8155f696>] ? kasan_unpoison_shadow+0x36/0x50
[ 1839.512504]  [<ffffffff8155f70e>] ? kasan_kmalloc+0x5e/0x70
[ 1839.512511]  [<ffffffffa1097352>] media_snd_mixer_init+0x292/0x500 [snd_usb_audio]
[ 1839.512519]  [<ffffffffa1097693>] media_snd_device_create+0xd3/0x2e0 [snd_usb_audio]
[ 1839.512525]  [<ffffffffa1059b05>] usb_audio_probe+0x695/0x1c90 [snd_usb_audio]
[ 1839.512529]  [<ffffffff8128b217>] ? debug_lockdep_rcu_enabled+0x77/0x90
[ 1839.512536]  [<ffffffffa1059470>] ? snd_usb_create_stream+0x4e0/0x4e0 [snd_usb_audio]
[ 1839.512540]  [<ffffffff812404fa>] ? trace_hardirqs_on_caller+0x40a/0x590
[ 1839.512543]  [<ffffffff8124068d>] ? trace_hardirqs_on+0xd/0x10
[ 1839.512546]  [<ffffffff81dbb1dd>] usb_probe_interface+0x45d/0x940
[ 1839.512550]  [<ffffffff81ce7e7a>] driver_probe_device+0x21a/0xc30
[ 1839.512553]  [<ffffffff81ce8890>] ? driver_probe_device+0xc30/0xc30
[ 1839.512556]  [<ffffffff81ce89b1>] __driver_attach+0x121/0x160
[ 1839.512559]  [<ffffffff81ce21bf>] bus_for_each_dev+0x11f/0x1a0
[ 1839.512562]  [<ffffffff81ce20a0>] ? subsys_dev_iter_exit+0x10/0x10
[ 1839.512565]  [<ffffffff822e7be7>] ? _raw_spin_unlock+0x27/0x40
[ 1839.512568]  [<ffffffff81ce6cdd>] driver_attach+0x3d/0x50
[ 1839.512571]  [<ffffffff81ce5df9>] bus_add_driver+0x4c9/0x770
[ 1839.512575]  [<ffffffff81cea39c>] driver_register+0x18c/0x3b0
[ 1839.512578]  [<ffffffff81250f92>] ? __raw_spin_lock_init+0x32/0x100
[ 1839.512581]  [<ffffffff81db6e98>] usb_register_driver+0x1f8/0x440
[ 1839.512584]  [<ffffffff810021a1>] ? do_one_initcall+0x131/0x300
[ 1839.512587]  [<ffffffffa10d8000>] ? 0xffffffffa10d8000
[ 1839.512594]  [<ffffffffa10d801e>] usb_audio_driver_init+0x1e/0x1000 [snd_usb_audio]
[ 1839.512597]  [<ffffffff810021b1>] do_one_initcall+0x141/0x300
[ 1839.512600]  [<ffffffff81002070>] ? try_to_run_init_process+0x40/0x40
[ 1839.512603]  [<ffffffff8155f696>] ? kasan_unpoison_shadow+0x36/0x50
[ 1839.512606]  [<ffffffff8155f696>] ? kasan_unpoison_shadow+0x36/0x50
[ 1839.512609]  [<ffffffff8155f7a7>] ? __asan_register_globals+0x87/0xa0
[ 1839.512613]  [<ffffffff8144d8eb>] do_init_module+0x1d0/0x5ad
[ 1839.512617]  [<ffffffff812f27b6>] load_module+0x6666/0x9ba0
[ 1839.512620]  [<ffffffff812e9e20>] ? symbol_put_addr+0x50/0x50
[ 1839.512627]  [<ffffffff812ec150>] ? module_frob_arch_sections+0x20/0x20
[ 1839.512630]  [<ffffffff815be010>] ? open_exec+0x50/0x50
[ 1839.512634]  [<ffffffff8116716b>] ? ns_capable+0x5b/0xd0
[ 1839.512637]  [<ffffffff812f5fe8>] SyS_finit_module+0x108/0x130
[ 1839.512640]  [<ffffffff812f5ee0>] ? SyS_init_module+0x1f0/0x1f0
[ 1839.512643]  [<ffffffff81004044>] ? lockdep_sys_exit_thunk+0x12/0x14
[ 1839.512647]  [<ffffffff822e8636>] entry_SYSCALL_64_fastpath+0x16/0x76
[ 1839.514027] usbcore: registered new interface driver snd-usb-audio

And an extra kmemleak issue:

unreferenced object 0xffff8803bcbacf30 (size 128):
  comm "modprobe", pid 2625, jiffies 4294950803 (age 1715.788s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
    00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
  backtrace:
    [<ffffffff822cf76e>] kmemleak_alloc+0x4e/0xb0
    [<ffffffff8155ab06>] kmem_cache_alloc_trace+0x236/0x300
    [<ffffffff81937eb2>] ida_pre_get+0x1a2/0x250
    [<ffffffff81938005>] ida_simple_get+0xa5/0x170
    [<ffffffffa0f1469a>] 0xffffffffa0f1469a
    [<ffffffffa0fe6951>] au0828_dvb_register+0xe21/0x12c0 [au0828]
    [<ffffffffa0fd1d92>] vb2_thread+0xbb2/0xc10 [videobuf2_core]
    [<ffffffff81dbb1dd>] usb_probe_interface+0x45d/0x940
    [<ffffffff81ce7e7a>] driver_probe_device+0x21a/0xc30
    [<ffffffff81ce89b1>] __driver_attach+0x121/0x160
    [<ffffffff81ce21bf>] bus_for_each_dev+0x11f/0x1a0
    [<ffffffff81ce6cdd>] driver_attach+0x3d/0x50
    [<ffffffff81ce5df9>] bus_add_driver+0x4c9/0x770
    [<ffffffff81cea39c>] driver_register+0x18c/0x3b0
    [<ffffffff81db6e98>] usb_register_driver+0x1f8/0x440
    [<ffffffffa0fb80b7>] au8522_get_frontend+0xb7/0x160 [au8522_dig]

I did one extra module removal/reinsert, and this time, I got lots
of bugs. Full dmesg is at:
	http://pastebin.com/LEX5LD5K

The Kernel hanged after a while with (at the serial console - with
kind of explain why the message is truncated):

[ 2117.282666] kasan: GPF could be caused by NULL-ptr deref or user memory accessgeneral protection fault: 0000 [#2] SMP KASAN
[ 2117.284074] Modules linked in: videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio 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 iTCO_vendor_support kvm irqbypass crct10dif_pclmul crc32_