[Xperia Z3 Compact Original Android Development] Mr.Tom_Tom:
Testing FMRadio & Call Volume

FMRadio not working for me, when connecting a headphone a notice (toast) appears with something like "Currently not available".

LogCat excerpt:

10-27 02:16:49.209 382 5329 D audio_hw_primary: start_output_stream: enter: stream(0xabc2f180)usecase(1: low-latency-playback) devices(0x4)
10-27 02:16:49.209 382 5329 D audio_hw_primary: start_output_stream: enter: usecase(1: low-latency-playback) devices(0x4)
10-27 02:16:49.209 382 5329 D audio_hw_extn: audio_extn_get_anc_enabled: anc_enabled:0
10-27 02:16:49.209 382 5329 D audio_hw_primary: select_devices: out_snd_device(4: headphones-regulation) in_snd_device(0: )
10-27 02:16:49.209 382 5329 W msm8974_platform: Codec backend bitwidth 16, samplerate 48000
10-27 02:16:49.209 382 5329 D hardware_info: hw_info_append_hw_type : device_name = headphones-regulation
10-27 02:16:49.209 382 5329 I msm8974_platform: platform_send_audio_calibration: sending audio calibration for snd_device(4) acdb_id(10)
10-27 02:16:49.209 382 5329 D ACDB-LOADER: ACDB -> send_audio_cal, acdb_id = 10, path = 0
10-27 02:16:49.209 382 5329 D ACDB-LOADER: ACDB -> send_adm_topology
10-27 02:16:49.209 382 5329 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TOPOLOGY_ID
10-27 02:16:49.209 382 5329 D ACDB-LOADER: ACDB -> send_asm_topology
10-27 02:16:49.209 382 5329 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_STREAM_TOPOLOGY_ID
10-27 02:16:49.209 382 5329 D ACDB-LOADER: ACDB -> send_audtable
10-27 02:16:49.209 382 5329 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TABLE
10-27 02:16:49.209 382 5329 D ACDB-LOADER: ACDB -> AUDIO_SET_AUDPROC_CAL
10-27 02:16:49.209 382 5329 D ACDB-LOADER: ACDB -> send_audvoltable
10-27 02:16:49.209 382 5329 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_GAIN_DEP_STEP_TABLE
10-27 02:16:49.209 382 5329 D ACDB-LOADER: ACDB -> AUDIO_SET_AUDPROC_VOL_CAL
10-27 02:16:49.209 382 5329 D ACDB-LOADER: ACDB -> AUDIO_SET_AFE_CAL
10-27 02:16:49.209 382 5329 D audio_route: Apply path: headphones-regulation
10-27 02:16:49.212 654 3872 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.android.fmradio/.FmMainActivity bnds=[23,884][191,1062]} from uid 10021
10-27 02:16:49.219 382 5329 D audio_route: Apply path: low-latency-playback
10-27 02:16:49.222 382 5329 D audio_hw_primary: select_devices: done
10-27 02:16:49.258 6460 6460 W ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@968ca44
10-27 02:16:49.307 6460 6460 D FmMainActivity: refreshStationUI, set station value null when it is first time
10-27 02:16:49.314 6460 6460 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.startService:1531 android.content.ContextWrapper.startService:664 com.android.fmradio.FmMainActivity.onStart:647 android.app.Instrumentation.callActivityOnStart:1391 android.app.Activity.performStart:7165
10-27 02:16:49.316 6460 6460 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.bindService:1611 android.content.ContextWrapper.bindService:698 com.android.fmradio.FmMainActivity.onStart:653 android.app.Instrumentation.callActivityOnStart:1391 android.app.Activity.performStart:7165
10-27 02:16:49.321 6460 6460 D FmMainActivity: onResume, mService is null
10-27 02:16:49.340 6460 6486 D FmService: onAudioPatchListUpdate, not power up
10-27 02:16:49.341 382 503 D AudioPolicyManagerCustom: setForceUse() usage 1, config 0, mPhoneState 0
10-27 02:16:49.359 382 637 D audio_hw_primary: out_set_parameters: enter: usecase(1: low-latency-playback) kvpairs: routing=4
10-27 02:16:49.364 382 637 D audio_hw_extn: audio_extn_get_anc_enabled: anc_enabled:0
10-27 02:16:49.364 382 637 D audio_hw_extn: audio_extn_set_anc_parameters: anc_enabled:0
10-27 02:16:49.368 382 6669 D audio_hw_primary: adev_open_input_stream: enter: sample_rate(44100) channel_mask(0xc) devices(0x80002000) stream_handle(0xac333ce0) io_handle(78) source(1998)
10-27 02:16:49.369 382 7757 I AudioFlinger: AudioFlinger's thread 0xa9383fc0 tid=7757 ready to run
10-27 02:16:49.369 382 7757 D audio_hw_primary: in_standby: enter: stream (0xac333ce0) usecase(17: audio-record)
10-27 02:16:49.372 382 7757 D audio_hw_primary: in_standby: enter: stream (0xac333ce0) usecase(17: audio-record)
10-27 02:16:49.375 382 6668 I AudioPolicyManagerCustom: setting force DEEP buffer now
10-27 02:16:49.376 382 6668 D AudioFlinger: Client defaulted notificationFrames to 1178 for frameCount 3536
10-27 02:16:49.377 6460 6460 W AudioTrack: Use of stream types is deprecated for operations other than volume control
10-27 02:16:49.377 6460 6460 W AudioTrack: See the documentation of AudioTrack() for what to use instead with android.media.AudioAttributes to qualify your playback use case
10-27 02:16:49.385 6460 6485 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
10-27 02:16:49.386 6460 6485 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8974.so from current namespace instead of sphal namespace.
10-27 02:16:49.388 6460 6460 D FmService: onReceive, action = android.intent.action.HEADSET_PLUG / command = null
10-27 02:16:49.388 6460 6460 D FmService: onReceive, mIsServiceInited is false
10-27 02:16:49.393 6460 7754 W AudioManager: Use of stream types is deprecated for operations other than volume control
10-27 02:16:49.393 6460 7754 W AudioManager: See the documentation of requestAudioFocus() for what to use instead with android.media.AudioAttributes to qualify your playback use case
10-27 02:16:49.393 654 4113 I MediaFocusControl: requestAudioFocus() from uid/pid 1000/6460 clientId=android.media.AudioManager@a86f512com.android.fmradio.FmService$2@80e04e3 callingPack=com.android.fmradio req=1 flags=0x0 sdk=23
10-27 02:16:49.394 6460 7754 I : androidFmRadioRxGetState, state
10-27 02:16:49.394 6460 7754 I : androidFmRadioRxStart. LowFreq 87500, HighFreq 108000, DefaultFreq 100000, grid 100.
10-27 02:16:49.394 6460 7754 E : No matching library found in path /system/lib/
10-27 02:16:49.394 6460 7754 E : vendor registration failed
10-27 02:16:49.394 6460 7754 I : androidFmRadioThrowException, java/io/IOException ('IO Exception') @ hardware/broadcom/fm/libfmjni/android_fm.cpp 724 (androidFmRadioStart)
10-27 02:16:49.410 6460 6460 D FmMainActivity: mHandler.handleMessage, what = 9,hashcode:109581418
10-27 02:16:49.410 6460 6460 D FmMainActivity: refreshStationUI, set station value null when it is first time
10-27 02:16:49.428 654 700 I ActivityManager: Displayed com.android.fmradio/.FmMainActivity: +202ms
10-27 02:16:49.435 6460 6485 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
10-27 02:16:49.435 6460 6485 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8974.so from current namespace instead of sphal namespace.
10-27 02:16:49.580 350 389 W SurfaceFlinger: Attempting to set client state on removed layer: Splash Screen com.android.fmradio#0
10-27 02:16:49.580 350 389 W SurfaceFlinger: Attempting to destroy on removed layer: Splash Screen com.android.fmradio#0
10-27 02:16:51.454 654 3960 W NotificationService: Toast already killed. pkg=com.android.fmradio callback=android.app.ITransientNotification$Stub$Proxy@c643439
10-27 02:16:51.964 350 389 W SurfaceFlinger: Attempting to destroy on removed layer: 58906c9 Toast#0
10-27 02:16:52.416 382 637 D audio_hw_primary: out_standby: enter: stream (0xabc2f180) usecase(1: low-latency-playback)
10-27 02:16:52.537 382 637 D hardware_info: hw_info_append_hw_type : device_name = headphones-regulation
10-27 02:16:54.862 324 324 W ice : type=1400 audit(0.0:835): avc: denied { read } for name="type" dev="sysfs" ino=19662 scontext=u:r:hal_health_default:s0 tcontext=u:object_r:sysfs:s0 tclass=file permissive=0
10-27 02:16:54.866 324 324 W ice : type=1400 audit(0.0:836): avc: denied { read } for name="type" dev="sysfs" ino=10736 scontext=u:r:hal_health_default:s0 tcontext=u:object_r:sysfs:s0 tclass=file permissive=0
10-27 02:16:54.892 325 325 D lights.msm8974: led [solid] = ffffff00
10-27 02:16:56.224 382 5329 D audio_hw_primary: start_output_stream: enter: stream(0xabc2f180)usecase(1: low-latency-playback) devices(0x4)
10-27 02:16:56.225 382 5329 D audio_hw_primary: start_output_stream: enter: usecase(1: low-latency-playback) devices(0x4)
10-27 02:16:56.225 382 5329 D audio_hw_extn: audio_extn_get_anc_enabled: anc_enabled:0
10-27 02:16:56.225 382 5329 D audio_hw_primary: select_devices: out_snd_device(4: headphones-regulation) in_snd_device(0: )
10-27 02:16:56.225 382 5329 W msm8974_platform: Codec backend bitwidth 16, samplerate 48000
10-27 02:16:56.225 382 5329 D hardware_info: hw_info_append_hw_type : device_name = headphones-regulation
10-27 02:16:56.225 382 5329 I msm8974_platform: platform_send_audio_calibration: sending audio calibration for snd_device(4) acdb_id(10)
10-27 02:16:56.225 382 5329 D ACDB-LOADER: ACDB -> send_audio_cal, acdb_id = 10, path = 0
10-27 02:16:56.225 382 5329 D ACDB-LOADER: ACDB -> send_adm_topology
10-27 02:16:56.225 382 5329 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TOPOLOGY_ID
10-27 02:16:56.225 382 5329 D ACDB-LOADER: ACDB -> send_asm_topology
10-27 02:16:56.225 382 5329 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_STREAM_TOPOLOGY_ID
10-27 02:16:56.225 382 5329 D ACDB-LOADER: ACDB -> send_audtable
10-27 02:16:56.225 382 5329 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TABLE
10-27 02:16:56.225 382 5329 D ACDB-LOADER: ACDB -> AUDIO_SET_AUDPROC_CAL
10-27 02:16:56.225 382 5329 D ACDB-LOADER: ACDB -> send_audvoltable
10-27 02:16:56.225 382 5329 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_GAIN_DEP_STEP_TABLE
10-27 02:16:56.225 382 5329 D ACDB-LOADER: ACDB -> AUDIO_SET_AUDPROC_VOL_CAL
10-27 02:16:56.225 382 5329 D ACDB-LOADER: ACDB -> AUDIO_SET_AFE_CAL
10-27 02:16:56.225 382 5329 D audio_route: Apply path: headphones-regulation
10-27 02:16:56.239 382 5329 D audio_route: Apply path: low-latency-playback
10-27 02:16:56.240 382 5329 D audio_hw_primary: select_devices: done
10-27 02:16:56.279 6460 6485 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
10-27 02:16:56.281 6460 6485 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8974.so from current namespace instead of sphal namespace.
10-27 02:16:59.436 382 637 D audio_hw_primary: out_standby: enter: stream (0xabc2f180) usecase(1: low-latency-playback)
10-27 02:16:59.575 382 637 D hardware_info: hw_info_append_hw_type : device_name = headphones-regulation

Note the "E : No matching library found in path /system/lib/"

Call volume

Still not working correctly I guess. I confirm what Dennis (@dhemker) wrote earlier.

Tried to get some insights with LogCat: https://pastebin.com/evLZcK6x

dmesg excerpt (this was a second try, so the timestamps are not in sync): https://pastebin.com/2UfwRVfA

And here's how the same device behaves on CarbonRom (latest Oreo build): https://pastebin.com/v6236UMj

Volume is lower during earpiece mode, and switching between the modes works smoothly.

Hope that helps to get a understanding what might be misconfigured.