AudioManager asserts on Connect of BT HFP/A2DP profiles

Description

After boot and clicking Connect in Settings for an already paired BT HFP/A2DP device, I see the following assert which seems to be from the sink name being empty:

May 12 12:19:34 porter AudioManager[486]: [DBP] [Info] cbNewSink called
May 12 12:19:34 porter AudioManager[486]: [DBP] [Info] send signal SinkAdded
May 12 12:20:36 porter AudioManager[486]: [DRS] [Info] registerSink
May 12 12:20:36 porter AudioManager[486]: [DRS] [Info] IAmRoutingReceiverShadow::registerSink called, namemSink.sinkClassID1 mSink.domainID100
May 12 12:20:36 porter AudioManager[486]: [AMCO] [Defa] >> CAmControlSend.cpphookSystemRegisterSink sink=
May 12 12:20:36 porter AudioManager[486]: [AMCO] [Defa] >> CAmSinkElement.cppconvertMainVolumeToVolume user volume:0
May 12 12:20:36 porter AudioManager[486]: [AMCO] [Defa] CAmSinkElement.cppconvertMainVolumeToVolume empty mapping0
May 12 12:20:36 porter AudioManager[486]: [AMCO] [Defa] >> CAmElement.cppsetVolume0
May 12 12:20:36 porter AudioManager[486]: AudioManager: /usr/src/debug/audiomanager/7.4-r0/git/AudioManagerCore/src/CAmDatabaseHandlerMap.cpp:560: virtual am::am_Error_e am::CAmDatabaseHandlerMap::enterSinkDB(const am::am_Sink_s&, am::am_sinkID_t&): Assertion `!sinkData.name.empty()' failed.
May 12 12:20:36 porter systemd[1]: audiomanager.service: Main process exited, code=dumped, status=6/ABRT
May 12 12:20:36 porter systemd[1]: audiomanager.service: Unit entered failed state.
May 12 12:20:36 porter systemd[1]: audiomanager.service: Failed with result 'core-dump'.
May 12 12:20:36 porter systemd[1]: audiomanager.service: Service hold-off time over, scheduling restart.

Note that the above log occurs when Sink #2 (BT audio gateway) is being processed. It handles Sink #0 and #1 fine, registering them properly. PA sink info follows:

Sink #0
 State: SUSPENDED
 Name: alsa_output.usb-JABRA_GN_2000_USB-00.analog-stereo
 Description: GN 2000 USB Analog Stereo
 Driver: module-alsa-card.c
 Sample Specification: s16le 2ch 44100Hz
 Channel Map: front-left,front-right
 Owner Module: 3
 Mute: no
 Volume: front-left: 65536 / 100% / 0.00 dB, front-right: 65536 / 100% / 0.00 dB
 balance 0.00
 Base Volume: 65536 / 100% / 0.00 dB
 Monitor Source: alsa_output.usb-JABRA_GN_2000_USB-00.analog-stereo.monitor
 Latency: 0 usec, configured 0 usec
 Flags: HARDWARE HW_MUTE_CTRL DECIBEL_VOLUME LATENCY 
 Properties:
 alsa.resolution_bits = "16"
 device.api = "alsa"
 device.class = "sound"
 alsa.class = "generic"
 alsa.subclass = "generic-mix"
 alsa.name = "USB Audio"
 alsa.id = "USB Audio"
 alsa.subdevice = "0"
 alsa.subdevice_name = "subdevice #0"
 alsa.device = "0"
 alsa.card = "1"
 alsa.card_name = "GN 2000 USB"
 alsa.long_card_name = "JABRA GN 2000 USB at usb-0002:01:02.0-1.4, full speed"
 alsa.driver_name = "snd_usb_audio"
 device.bus_path = "platform-pci-rcar-gen2.1-pci-0002:01:02.0-usb-0:1.4:1.0"
 sysfs.path = "/devices/platform/pci-rcar-gen2.1/pci0002:01/0002:01:02.0/usb2/2-1/2-1.4/2-1.4:1.0/sound/card1"
 udev.id = "usb-JABRA_GN_2000_USB-00"
 device.bus = "usb"
 device.vendor.id = "0b0e"
 device.vendor.name = "GN Netcom"
 device.product.id = "2003"
 device.product.name = "GN 2000 USB"
 device.serial = "JABRA_GN_2000_USB"
 device.string = "front:1"
 device.buffering.buffer_size = "352800"
 device.buffering.fragment_size = "176400"
 device.access_mode = "mmap+timer"
 device.profile.name = "analog-stereo"
 device.profile.description = "Analog Stereo"
 device.description = "GN 2000 USB Analog Stereo"
 alsa.mixer_name = "USB Mixer"
 alsa.components = "USB0b0e:2003"
 module-udev-detect.discovered = "1"
 device.icon_name = "audio-card-usb"
 Ports:
 analog-output-speaker: Speakers (priority: 10000)
 Active Port: analog-output-speaker
 Formats:
 pcm
Sink #1
 State: SUSPENDED
 Name: alsa_output.platform-sound.6.analog-stereo
 Description: rsnd-dai.0-ak4642-hifi Analog Stereo
 Driver: module-alsa-card.c
 Sample Specification: s16le 2ch 44100Hz
 Channel Map: front-left,front-right
 Owner Module: 4
 Mute: no
 Volume: front-left: 65536 / 100% / 0.00 dB, front-right: 65536 / 100% / 0.00 dB
 balance 0.00
 Base Volume: 65536 / 100% / 0.00 dB
 Monitor Source: alsa_output.platform-sound.6.analog-stereo.monitor
 Latency: 0 usec, configured 0 usec
 Flags: HARDWARE DECIBEL_VOLUME LATENCY 
 Properties:
 alsa.resolution_bits = "16"
 device.api = "alsa"
 device.class = "sound"
 alsa.class = "generic"
 alsa.subclass = "generic-mix"
 alsa.name = ""
 alsa.id = "rsnd-dai.0-ak4642-hifi ak4642-hifi-0"
 alsa.subdevice = "0"
 alsa.subdevice_name = "subdevice #0"
 alsa.device = "0"
 alsa.card = "0"
 alsa.card_name = "rsnd-dai.0-ak4642-hifi"
 alsa.long_card_name = "rsnd-dai.0-ak4642-hifi"
 device.bus_path = "platform-sound.6"
 sysfs.path = "/devices/sound.6/sound/card0"
 device.string = "hw:0"
 device.buffering.buffer_size = "32768"
 device.buffering.fragment_size = "8192"
 device.access_mode = "mmap+timer"
 device.profile.name = "analog-stereo"
 device.profile.description = "Analog Stereo"
 device.description = "rsnd-dai.0-ak4642-hifi Analog Stereo"
 module-udev-detect.discovered = "1"
 device.icon_name = "audio-card"
 Ports:
 analog-output: Analog Output (priority: 9900)
 Active Port: analog-output
 Formats:
 pcm
Sink #2
 State: SUSPENDED
 Name: bluez_sink.44_80_EB_23_13_97
 Description: Nexus 6
 Driver: module-bluez5-device.c
 Sample Specification: s16le 1ch 8000Hz
 Channel Map: mono
 Owner Module: 19
 Mute: no
 Volume: mono: 65536 / 100% / 0.00 dB
 balance 0.00
 Base Volume: 65536 / 100% / 0.00 dB
 Monitor Source: bluez_sink.44_80_EB_23_13_97.monitor
 Latency: 0 usec, configured 0 usec
 Flags: HARDWARE DECIBEL_VOLUME LATENCY 
 Properties:
 bluetooth.protocol = "headset_audio_gateway"
 device.description = "Nexus 6"
 device.string = "44:80:EB:23:13:97"
 device.api = "bluez"
 device.class = "sound"
 device.bus = "bluetooth"
 device.form_factor = "phone"
 bluez.path = "/org/bluez/hci0/dev_44_80_EB_23_13_97"
 bluez.class = "0x5a020c"
 bluez.alias = "Nexus 6"
 device.icon_name = "audio-card-bluetooth"
 Ports:
 phone-output: Phone (priority: 0)
 Active Port: phone-output
 Formats:
 pcm

After systemd restarts AudioManager it doesn't crash again, but I get domain errors when it's adding sinks:

May 12 12:37:19 porter AudioManager[1189]: [DEF] [Erro] am::am_Error_e am::CAmRoutingSender::addSinkLookup(const am::a
m_Sink_s&)Could not find domainInterface for domainID100

Environment

porter board master build from 8 June AudioManager logging enabled

Linked work items

relates to

SPEC-710

phone role sink inputs and source outputs stuck in corked state

Activity

Show:

Matt Porter
July 5, 2017 at 11:28 AM

Fix merged at https://github.com/tisogai/module-router/commit/8104a3174e6f54ace53066ab1797d9b9bd2bdf63

Matt Porter
June 27, 2017 at 4:12 PM

To clarify some of the adverse effects of this bug, I should point out that it would result in some sink inputs being left in a muted state. Particularly, this seems to be triggered by bluetooth audio card sink inputs and source outputs and the result is no audio unless the sink input has the mute toggled off. Once the patch is applied, the policy behavior is as expected where these same sink inputs and source outputs are unmuted and uncorked as directed by the default AM configuration present in AGL demo builds.

Matt Porter
June 26, 2017 at 1:23 PM

I just sent a pull request at https://github.com/tisogai/module-router/pull/6 to fix this upstream. If applied we can simply update the recipe SRCREV to fix in AGL.

Fix access of empty proplist description
 
 When adding a new sink or source, the router module fires
 hook_callback_[sink|source]_new() with the new sink/source
 data. The pulseaudio core fires the PA_CORE_HOOK_SINK_NEW and
 PA_CORE_HOOK_SOURCE_NEW hooks before proplist is initialized
 in the supplied data argument. The result is that in certain
 cases, the callback routine runs and finds an null string for
 the device description property which registers an empty sink
 or source for AudioManager thereby causing AudioManager to
 assert on the empty sink/source name. This is fixed by hooking
 the later PA_CORE_HOOK_SINK_FIXATE and PA_CORE_HOOK_SOURCE_FIXATE
 hooks which are fired after proplist has been initialized.

Resize issue view side panel

Fixed

Details

Assignee

Matt Porter

Reporter

Matt Porter

Fix versions

Dab

Eel

Labels

Contract ID

Components

Audio Manager

Affects versions

Dab

Priority

Major

Created June 12, 2017 at 6:04 PM

Updated July 24, 2017 at 11:45 PM

Resolved July 7, 2017 at 12:54 PM