search

sonyxperiadev / bug_tracker

Empty repository that is used as a bugtracker for Open Devices project
52 stars 13 forks source link

[yoshino][lilac] Speakers are no longer working #344

Closed stefanhh0 closed 5 years ago

stefanhh0 commented 5 years ago

Platform: yoshino Device: lilac Kernel version: 4.9.158-gcaee277f4487 Android version: android-9.0.0_r31 OEM Image: SW_binaries_for_Xperia_Android_9.0_2.3.2_v6_yoshino.img Build: aosp_g8441-userdebug 9 PQ2A.190205.001 eng.stefan.20190222.201553

Description The phone speakers are no longer working. No music, no phone ringing, no alarm. Connecting external speakers via cable has the same symptoms. It still works via bluetooth connected external speakers.

Phone calls itself seem not to be affected.

djselbeck commented 5 years ago

I can confirm this. It works for some time after reboot. Once it stopped after playing a notification sound.

jerpelea commented 5 years ago

I can not replicate the issue on a clean build with userdata wiped please do a clean build and if the issue is still present post the steps to replicate the issue

stefanhh0 commented 5 years ago

Flashed the clean build today again that I originally made on 22nd Feb It also contains the latest relevant commit sonyxperiadev/device-sony-lilac/commit@7170bbaf1980188cdf4be15e3c31ecd5f5255e67

Flash protocol:

root@mars:/home/stefan/android/bin/current# ls -la
insgesamt 24
drwxr-xr-x 1 stefan stefan 118 Feb 23 06:47 .
drwxr-xr-x 1 stefan stefan 200 Feb 24 13:53 ..
lrwxrwxrwx 1 stefan stefan  22 Feb 23 06:47 boot.img -> ../2019_02_22/boot.img
lrwxrwxrwx 1 stefan stefan  58 Feb 22 20:38 oem.img -> ../SW_binaries_for_Xperia_Android_9.0_2.3.2_v6_yoshino.img
lrwxrwxrwx 1 stefan stefan  31 Jan 25 01:51 recovery.img -> ../twrp-3.2.3-0-lilac-pie-2.img
lrwxrwxrwx 1 stefan stefan  24 Feb 23 06:47 system.img -> ../2019_02_22/system.img
lrwxrwxrwx 1 stefan stefan  26 Feb 23 06:47 userdata.img -> ../2019_02_22/userdata.img
lrwxrwxrwx 1 stefan stefan  24 Feb 23 06:47 vendor.img -> ../2019_02_22/vendor.img
root@mars:/home/stefan/android/bin/current# fastboot flash boot boot.img 
target reported max download size of 536870912 bytes
sending 'boot' (16245 KB)...
OKAY [  0.525s]
writing 'boot'...
OKAY [  0.119s]
finished. total time: 0.644s
root@mars:/home/stefan/android/bin/current# fastboot flash oem oem.img 
target reported max download size of 536870912 bytes
sending 'oem' (209868 KB)...
OKAY [  6.991s]
writing 'oem'...
OKAY [  1.630s]
finished. total time: 8.621s
root@mars:/home/stefan/android/bin/current# fastboot flash system system.img 
target reported max download size of 536870912 bytes
erasing 'system'...
OKAY [ 10.202s]
sending sparse 'system' 1/3 (524284 KB)...
OKAY [ 17.450s]
writing 'system' 1/3...
OKAY [  0.000s]
sending sparse 'system' 2/3 (524284 KB)...
OKAY [ 17.750s]
writing 'system' 2/3...
OKAY [  0.000s]
sending sparse 'system' 3/3 (132332 KB)...
OKAY [  4.630s]
writing 'system' 3/3...
OKAY [  0.000s]
finished. total time: 50.032s
root@mars:/home/stefan/android/bin/current# fastboot flash userdata userdata.img 
target reported max download size of 536870912 bytes
erasing 'userdata'...
OKAY [ 14.799s]
sending 'userdata' (4832 KB)...
OKAY [  0.169s]
writing 'userdata'...
OKAY [  0.000s]
finished. total time: 14.969s
root@mars:/home/stefan/android/bin/current# fastboot flash vendor vendor.img 
target reported max download size of 536870912 bytes
sending 'vendor' (53028 KB)...
OKAY [  1.665s]
writing 'vendor'...
OKAY [  0.001s]
finished. total time: 1.666s

On last sunday I've switched to: Version baseband: 1307-7511_47.2.A.6.30 However when the problem occurred originally I was on: Version baseband: 1307-7511_47.2.A.2.33 Therefore I believe that the version baseband should make no difference for this issue. All the other Version info is the same as I posted in my first comment above.

After flashing I've booted into system: Settings -> Sound -> Phone ringtone I've tried several ringtones like "Flutey Phone", "Gimme Mo' Town" and others but no sound through the speaker. All the volume switches were set to high values (default).

I guess following snippet shows one attempt playing such a ringtone:

02-23 00:03:20.513   724   851 D NuPlayerDriver: NuPlayerDriver(0xe4fa1200) created, clientPid(2464)
02-23 00:03:20.526   724  3624 D GenericSource: FileSource remote
02-23 00:03:20.534   724   851 D NuPlayerDriver: NuPlayerDriver(0xe4fa1980) created, clientPid(2464)
02-23 00:03:20.536   724  3623 D NuPlayerDriver: notifyListener_l(0xe4fa1200), (1, 0, 0, -1), loop setting(0, 0)
02-23 00:03:20.545  2464  3621 D Ringtone: Successfully created local player
02-23 00:03:20.545   724  3629 D GenericSource: FileSource remote
02-23 00:03:20.545  2464  3621 W Ringtone: Use of stream types is deprecated for operations other than volume control
02-23 00:03:20.546  2464  3621 W Ringtone: See the documentation of setStreamType() for what to use instead with android.media.AudioAttributes to qualify your playback use case
02-23 00:03:20.547   724   851 D NuPlayerDriver: reset(0xe4fa1200) at state 4
02-23 00:03:20.547   724   851 D NuPlayerDriver: notifyListener_l(0xe4fa1200), (8, 0, 0, -1), loop setting(0, 0)
02-23 00:03:20.549   724  3623 D NuPlayerDriver: notifyResetComplete(0xe4fa1200)
02-23 00:03:20.550   724   851 D NuPlayerDriver: reset(0xe4fa1200) at state 0
02-23 00:03:20.552  2464  3621 V MediaPlayer: resetDrmState:  mDrmInfo=null mDrmProvisioningThread=null mPrepareDrmInProgress=false mActiveDrmScheme=false
02-23 00:03:20.552  2464  3621 V MediaPlayer: cleanDrmObj: mDrmObj=null mDrmSessionId=null
02-23 00:03:20.555  2464  3621 V MediaPlayer: resetDrmState:  mDrmInfo=null mDrmProvisioningThread=null mPrepareDrmInProgress=false mActiveDrmScheme=false
02-23 00:03:20.556  2464  3621 V MediaPlayer: cleanDrmObj: mDrmObj=null mDrmSessionId=null
02-23 00:03:20.557   724  3627 D NuPlayerDriver: notifyListener_l(0xe4fa1980), (1, 0, 0, -1), loop setting(0, 0)
02-23 00:03:20.560  2464  3625 D Ringtone: Successfully created local player
02-23 00:03:20.561  2464  3625 W Ringtone: Use of stream types is deprecated for operations other than volume control
02-23 00:03:20.561  2464  3625 W Ringtone: See the documentation of setStreamType() for what to use instead with android.media.AudioAttributes to qualify your playback use case
02-23 00:03:20.563   724   851 D NuPlayerDriver: reset(0xe4fa1980) at state 4
02-23 00:03:20.563   724   851 D NuPlayerDriver: notifyListener_l(0xe4fa1980), (8, 0, 0, -1), loop setting(1, 0)
02-23 00:03:20.564   724  3627 D NuPlayerDriver: notifyResetComplete(0xe4fa1980)
02-23 00:03:20.565   724  2445 D NuPlayerDriver: NuPlayerDriver(0xe6913100) created, clientPid(2464)
02-23 00:03:20.565   724  3418 D NuPlayerDriver: NuPlayerDriver(0xe4fa1380) created, clientPid(2464)
02-23 00:03:20.574   724   851 D NuPlayerDriver: reset(0xe4fa1980) at state 0
02-23 00:03:20.575  2464  3625 V MediaPlayer: resetDrmState:  mDrmInfo=null mDrmProvisioningThread=null mPrepareDrmInProgress=false mActiveDrmScheme=false
02-23 00:03:20.575  2464  3625 V MediaPlayer: cleanDrmObj: mDrmObj=null mDrmSessionId=null
02-23 00:03:20.576  2464  3625 V MediaPlayer: resetDrmState:  mDrmInfo=null mDrmProvisioningThread=null mPrepareDrmInProgress=false mActiveDrmScheme=false
02-23 00:03:20.577  2464  3625 V MediaPlayer: cleanDrmObj: mDrmObj=null mDrmSessionId=null
02-23 00:03:20.577   724  3637 D GenericSource: FileSource remote
02-23 00:03:20.580   724  2445 D NuPlayerDriver: NuPlayerDriver(0xe4fa1a00) created, clientPid(2464)
02-23 00:03:20.581   724   851 D NuPlayerDriver: NuPlayerDriver(0xe4fa1980) created, clientPid(2464)
02-23 00:03:20.585   724  3634 D NuPlayerDriver: notifyListener_l(0xe6913100), (1, 0, 0, -1), loop setting(0, 0)
02-23 00:03:20.588   724  3645 D GenericSource: FileSource remote
02-23 00:03:20.592  2464  3632 D Ringtone: Successfully created local player
02-23 00:03:20.592  2464  3632 W Ringtone: Use of stream types is deprecated for operations other than volume control
02-23 00:03:20.593  2464  3632 W Ringtone: See the documentation of setStreamType() for what to use instead with android.media.AudioAttributes to qualify your playback use case
02-23 00:03:20.593   724  2445 D NuPlayerDriver: reset(0xe6913100) at state 4
02-23 00:03:20.593   724  2445 D NuPlayerDriver: notifyListener_l(0xe6913100), (8, 0, 0, -1), loop setting(1, 0)
02-23 00:03:20.594   724  3641 D NuPlayerDriver: notifyListener_l(0xe4fa1a00), (1, 0, 0, -1), loop setting(0, 0)
02-23 00:03:20.594   724  3634 D NuPlayerDriver: notifyResetComplete(0xe6913100)
02-23 00:03:20.595   724  2445 D NuPlayerDriver: reset(0xe6913100) at state 0
02-23 00:03:20.595   724  3644 D GenericSource: FileSource remote
02-23 00:03:20.596  2464  3632 V MediaPlayer: resetDrmState:  mDrmInfo=null mDrmProvisioningThread=null mPrepareDrmInProgress=false mActiveDrmScheme=false
02-23 00:03:20.597   724  3639 D GenericSource: FileSource remote
02-23 00:03:20.597  2464  3632 V MediaPlayer: cleanDrmObj: mDrmObj=null mDrmSessionId=null
02-23 00:03:20.598  2464  3632 V MediaPlayer: resetDrmState:  mDrmInfo=null mDrmProvisioningThread=null mPrepareDrmInProgress=false mActiveDrmScheme=false
02-23 00:03:20.598  2464  3632 V MediaPlayer: cleanDrmObj: mDrmObj=null mDrmSessionId=null
02-23 00:03:20.601   724  3643 D NuPlayerDriver: notifyListener_l(0xe4fa1980), (1, 0, 0, -1), loop setting(0, 0)
02-23 00:03:20.602  2464  3625 D Ringtone: Successfully created local player
02-23 00:03:20.603   724   851 D NuPlayerDriver: NuPlayerDriver(0xe4fa1a80) created, clientPid(2464)
02-23 00:03:20.608  2464  3638 D Ringtone: Successfully created local player
02-23 00:03:20.608   724  3636 D NuPlayerDriver: notifyListener_l(0xe4fa1380), (1, 0, 0, -1), loop setting(0, 0)
02-23 00:03:20.609  2464  3638 W Ringtone: Use of stream types is deprecated for operations other than volume control
02-23 00:03:20.609  2464  3638 W Ringtone: See the documentation of setStreamType() for what to use instead with android.media.AudioAttributes to qualify your playback use case
02-23 00:03:20.610   724  2445 D NuPlayerDriver: reset(0xe4fa1980) at state 4
02-23 00:03:20.610   724  2445 D NuPlayerDriver: notifyListener_l(0xe4fa1980), (8, 0, 0, -1), loop setting(1, 0)
02-23 00:03:20.611   724  3653 D GenericSource: FileSource remote
02-23 00:03:20.611   724  3643 D NuPlayerDriver: notifyResetComplete(0xe4fa1980)
02-23 00:03:20.612   724  2445 D NuPlayerDriver: reset(0xe4fa1980) at state 0
02-23 00:03:20.613  2464  3638 V MediaPlayer: resetDrmState:  mDrmInfo=null mDrmProvisioningThread=null mPrepareDrmInProgress=false mActiveDrmScheme=false
02-23 00:03:20.613  2464  3638 V MediaPlayer: cleanDrmObj: mDrmObj=null mDrmSessionId=null
02-23 00:03:20.614  2464  3638 V MediaPlayer: resetDrmState:  mDrmInfo=null mDrmProvisioningThread=null mPrepareDrmInProgress=false mActiveDrmScheme=false
02-23 00:03:20.614  2464  3638 V MediaPlayer: cleanDrmObj: mDrmObj=null mDrmSessionId=null
02-23 00:03:20.617  2464  3621 D Ringtone: Successfully created local player
02-23 00:03:20.620   724   851 D NuPlayerDriver: NuPlayerDriver(0xe4fa1200) created, clientPid(2464)
02-23 00:03:20.624   724  3651 D NuPlayerDriver: notifyListener_l(0xe4fa1a80), (1, 0, 0, -1), loop setting(0, 0)
02-23 00:03:20.626  2464  3632 D Ringtone: Successfully created local player
02-23 00:03:20.627   724  3656 D GenericSource: FileSource remote
02-23 00:03:20.632   724  3655 D NuPlayerDriver: notifyListener_l(0xe4fa1200), (1, 0, 0, -1), loop setting(0, 0)

Furthermore while trying this an unwanted reboot occured, I have saved the pstore and additionally the dropbox. Maybe that is of any help for you?!

Flies: Logcat of the first bootup after flash and trying to play the ringtones: adb_logcat.log dropbox.tar.gz pstore.tar.gz

stefanhh0 commented 5 years ago

It works for some time after reboot. Once it stopped after playing a notification sound.

Interesting, I haven't managed to play something over the speaker not even after fresh reboot and trying being very quick... but maybe I wasn't just quick enough...

stefanhh0 commented 5 years ago

This looks also not so good, but maybe it is just normal?!:

02-11 12:21:02.128   617   866 E audio_route: Control 'MultiMedia4 Mixer MI2S_TX' doesn't exist - skipping
02-11 12:21:02.128   617   866 E audio_route: Control 'MultiMedia7 Mixer MI2S_TX' doesn't exist - skipping
02-11 12:21:02.128   617   866 E audio_route: Control 'MultiMedia11 Mixer MI2S_TX' doesn't exist - skipping
02-11 12:21:02.129   617   866 E audio_route: Control 'MultiMedia12 Mixer MI2S_TX' doesn't exist - skipping
02-11 12:21:02.129   617   866 E audio_route: Control 'MultiMedia13 Mixer MI2S_TX' doesn't exist - skipping
02-11 12:21:02.130   617   866 E audio_route: Control 'MultiMedia14 Mixer MI2S_TX' doesn't exist - skipping
02-11 12:21:02.130   617   866 E audio_route: Control 'MultiMedia15 Mixer MI2S_TX' doesn't exist - skipping
02-11 12:21:02.137   608   608 I PackageBackwardCompatibility: Loaded android.content.pm.OrgApacheHttpLegacyUpdater
02-11 12:21:02.137   608   608 I PackageBackwardCompatibility: Could not find android.content.pm.AndroidTestBaseUpdater, ignoring
02-11 12:21:02.145   617   866 E audio_route: Control 'LSM1 MUX' doesn't exist - skipping
02-11 12:21:02.145   617   866 E audio_route: Control 'LSM2 MUX' doesn't exist - skipping
02-11 12:21:02.146   617   866 E audio_route: Control 'LSM3 MUX' doesn't exist - skipping
02-11 12:21:02.146   617   866 E audio_route: Control 'LSM4 MUX' doesn't exist - skipping
02-11 12:21:02.147   617   866 E audio_route: Control 'LSM5 MUX' doesn't exist - skipping
02-11 12:21:02.147   617   866 E audio_route: Control 'LSM6 MUX' doesn't exist - skipping
02-11 12:21:02.147   617   866 E audio_route: Control 'LSM7 MUX' doesn't exist - skipping
02-11 12:21:02.148   617   866 E audio_route: Control 'LSM8 MUX' doesn't exist - skipping
02-11 12:21:02.149   617   866 E audio_route: Control 'Set Custom Stereo' doesn't exist - skipping
02-11 12:21:02.151   617   866 E audio_route: Control 'SLIMBUS_0_RX Audio Mixer MultiMedia1' already exists in path 'deep-buffer-playback speaker-and-headphones'
02-11 12:21:02.152   617   866 E audio_route: Control 'SLIMBUS_0_RX Audio Mixer MultiMedia5' already exists in path 'low-latency-playback speaker-and-headphones'
02-11 12:21:02.153   617   866 E audio_route: Control 'SLIMBUS_0_RX Audio Mixer MultiMedia3' already exists in path 'audio-ull-playback speaker-and-headphones'
02-11 12:21:02.155   617   866 E audio_route: Control 'SLIMBUS_0_RX Audio Mixer MultiMedia4' already exists in path 'compress-offload-playback speaker-and-headphones'
02-11 12:21:02.156   617   866 E audio_route: Control 'SLIMBUS_0_RX Audio Mixer MultiMedia7' already exists in path 'compress-offload-playback2 speaker-and-headphones'
02-11 12:21:02.158   617   866 E audio_route: Control 'SLIMBUS_0_RX Audio Mixer MultiMedia11' already exists in path 'compress-offload-playback4 speaker-and-headphones'
02-11 12:21:02.159   617   866 E audio_route: Control 'SLIMBUS_0_RX Audio Mixer MultiMedia12' already exists in path 'compress-offload-playback5 speaker-and-headphones'
02-11 12:21:02.160   617   866 E audio_route: Control 'SLIMBUS_0_RX Audio Mixer MultiMedia13' already exists in path 'compress-offload-playback6 speaker-and-headphones'
02-11 12:21:02.161   617   866 E audio_route: Control 'SLIMBUS_0_RX Audio Mixer MultiMedia14' already exists in path 'compress-offload-playback7 speaker-and-headphones'
02-11 12:21:02.162   617   866 E audio_route: Control 'SLIMBUS_0_RX Audio Mixer MultiMedia15' already exists in path 'compress-offload-playback8 speaker-and-headphones'
02-11 12:21:02.163   617   866 E audio_route: Control 'SLIMBUS_0_RX Audio Mixer MultiMedia16' already exists in path 'compress-offload-playback9 speaker-and-headphones'
02-11 12:21:02.167   617   866 E audio_route: Control 'AUX PCM SampleRate' doesn't exist - skipping
02-11 12:21:02.175   617   866 E audio_route: Control 'LSM1 MUX' doesn't exist - skipping
02-11 12:21:02.175   617   866 E audio_route: Control 'LSM2 MUX' doesn't exist - skipping
02-11 12:21:02.176   617   866 E audio_route: Control 'LSM3 MUX' doesn't exist - skipping
02-11 12:21:02.176   617   866 E audio_route: Control 'LSM4 MUX' doesn't exist - skipping
02-11 12:21:02.177   617   866 E audio_route: Control 'LSM5 MUX' doesn't exist - skipping
02-11 12:21:02.177   617   866 E audio_route: Control 'LSM6 MUX' doesn't exist - skipping
02-11 12:21:02.178   617   866 E audio_route: Control 'LSM7 MUX' doesn't exist - skipping
02-11 12:21:02.178   617   866 E audio_route: Control 'LSM8 MUX' doesn't exist - skipping
02-11 12:21:02.182   617   866 E audio_route: Control 'Set Custom Stereo' doesn't exist - skipping
02-11 12:21:02.183   617   866 E audio_route: Control 'Set Custom Stereo' doesn't exist - skipping
02-11 12:21:02.185   617   866 E audio_route: Control 'RX INT8 VBAT SPKRL VBAT Enable' doesn't exist - skipping
02-11 12:21:02.190   617   866 E audio_route: Control 'RX INT8 VBAT SPKRL VBAT Enable' doesn't exist - skipping
02-11 12:21:02.194   617   866 E audio_route: Control 'Set Custom Stereo' doesn't exist - skipping
02-11 12:21:02.195   617   866 E audio_route: Control 'SLIM RX0 MUX' already exists in path 'speaker-and-headphones-liquid'
02-11 12:21:02.200   617   866 E audio_route: unknown enum value string ZERO for ctl ADC MUX7
02-11 12:21:02.200   617   866 E audio_route: unknown enum value string ZERO for ctl ADC MUX8
02-11 12:21:02.208   617   866 E audio_route: unknown enum value string ZERO for ctl ADC MUX10
02-11 12:21:02.208   617   866 E audio_route: unknown enum value string ZERO for ctl ADC MUX12
02-11 12:21:02.212   617   866 E audio_route: Control 'Set Custom Stereo' doesn't exist - skipping
02-11 12:21:02.216   617   866 I chatty  : uid=1041(audioserver) HwBinder:617_1 identical 6 lines
02-11 12:21:02.216   617   866 E audio_route: Control 'Set Custom Stereo' doesn't exist - skipping
02-11 12:21:02.217   617   866 E audio_route: unknown enum value string ZERO for ctl ADC MUX10
02-11 12:21:02.217   617   866 E audio_route: unknown enum value string ZERO for ctl ADC MUX12
02-11 12:21:02.235   657   657 I /odm/bin/pm-service: type=1400 audit(0.0:53): avc: denied { ioctl } for comm=504F5349582074696D65722030 path="/dev/binder" dev="tmpfs" ino=16589 ioctlcmd=0x6201 scontext=u:r:per_mgr:s0 tcontext=u:object_r:binder_device:s0 tclass=chr_file permissive=1
02-11 12:21:02.236   755   755 I Binder:755_2: type=1400 audit(0.0:54): avc: denied { ioctl } for path="/dev/binder" dev="tmpfs" ino=16589 ioctlcmd=0x6201 scontext=u:r:wcnss_service:s0 tcontext=u:object_r:binder_device:s0 tclass=chr_file permissive=1
02-11 12:21:02.236   707   707 I Binder:707_2: type=1400 audit(0.0:55): avc: denied { ioctl } for path="/dev/binder" dev="tmpfs" ino=16589 ioctlcmd=0x6201 scontext=u:r:per_proxy:s0 tcontext=u:object_r:binder_device:s0 tclass=chr_file permissive=1
02-11 12:21:02.236   739   739 I rild    : type=1400 audit(0.0:56): avc: denied { ioctl } for path="/dev/binder" dev="tmpfs" ino=16589 ioctlcmd=0x6201 scontext=u:r:rild:s0 tcontext=u:object_r:binder_device:s0 tclass=chr_file permissive=1
02-11 12:21:02.237   657   687 D PerMgrSrv: modem new state: is on-line
02-11 12:21:02.237   617   866 D msm8974_platform: platform_init: Opened sound card:0
02-11 12:21:02.238   657   692 D PerMgrSrv: modem state: is on-line, add client QCRIL
02-11 12:21:02.238   657   692 D PerMgrSrv: QCRIL registered
02-11 12:21:02.238   739   739 D PerMgrLib: QCRIL successfully registered for modem
02-11 12:21:02.251   617   866 D ACDB-LOADER: ACDB -> Load file: /vendor/etc/acdbdata/Speaker_cal.acdb
02-11 12:21:02.251   617   866 D ACDB-LOADER: ACDB -> Load file: /vendor/etc/acdbdata/Hdmi_cal.acdb
02-11 12:21:02.252   617   866 D ACDB-LOADER: ACDB -> Load file: /vendor/etc/acdbdata/Global_cal.acdb
02-11 12:21:02.252   617   866 D ACDB-LOADER: ACDB -> Load file: /vendor/etc/acdbdata/General_cal.acdb
02-11 12:21:02.252   617   866 D ACDB-LOADER: ACDB -> Load file: /vendor/etc/acdbdata/Handset_cal.acdb
02-11 12:21:02.253   617   866 D ACDB-LOADER: ACDB -> Load file: /vendor/etc/acdbdata/Headset_cal.acdb
02-11 12:21:02.253   617   866 D ACDB-LOADER: ACDB -> Load file: /vendor/etc/acdbdata/Bluetooth_cal.acdb
02-11 12:21:02.253   617   866 D ACDB-LOADER: ACDB -> found 7 form factor & soundcard independant files
02-11 12:21:02.253   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_INITIALIZE_V2
02-11 12:21:02.256   617   866 D         : [ACDB Command]->SW Minor/Major/Revision version info for /vendor/etc/acdbdata/Speaker_cal.acdb
02-11 12:21:02.256   617   866 D         : [ACDB Command]->ACDB Sw Major = 9, ACDB Sw Minor = 0, ACDB Sw Revision = 4, ACDB Sw Cpl Number = 0
02-11 12:21:02.257   617   866 D         : [ACDB Command]->ACDB File Major = 9, ACDB File Minor = 0, ACDB File Revision = 10
02-11 12:21:02.258   617   866 D         : [ACDB Command]->SW Minor/Major/Revision version info for /vendor/etc/acdbdata/Hdmi_cal.acdb
02-11 12:21:02.258   617   866 D         : [ACDB Command]->ACDB Sw Major = 9, ACDB Sw Minor = 0, ACDB Sw Revision = 4, ACDB Sw Cpl Number = 0
02-11 12:21:02.259   617   866 D         : [ACDB Command]->ACDB File Major = 9, ACDB File Minor = 0, ACDB File Revision = 10
02-11 12:21:02.261   617   866 D         : [ACDB Command]->SW Minor/Major/Revision version info for /vendor/etc/acdbdata/Global_cal.acdb
02-11 12:21:02.261   617   866 D         : [ACDB Command]->ACDB Sw Major = 9, ACDB Sw Minor = 0, ACDB Sw Revision = 4, ACDB Sw Cpl Number = 0
02-11 12:21:02.261   617   866 D         : [ACDB Command]->ACDB File Major = 9, ACDB File Minor = 0, ACDB File Revision = 10
02-11 12:21:02.262   617   866 D         : [ACDB Command]->SW Minor/Major/Revision version info for /vendor/etc/acdbdata/General_cal.acdb
02-11 12:21:02.263   617   866 D         : [ACDB Command]->ACDB Sw Major = 9, ACDB Sw Minor = 0, ACDB Sw Revision = 4, ACDB Sw Cpl Number = 0
02-11 12:21:02.263   617   866 D         : [ACDB Command]->ACDB File Major = 9, ACDB File Minor = 0, ACDB File Revision = 10
02-11 12:21:02.265   617   866 D         : [ACDB Command]->SW Minor/Major/Revision version info for /vendor/etc/acdbdata/Handset_cal.acdb
02-11 12:21:02.265   617   866 D         : [ACDB Command]->ACDB Sw Major = 9, ACDB Sw Minor = 0, ACDB Sw Revision = 4, ACDB Sw Cpl Number = 0
02-11 12:21:02.265   617   866 D         : [ACDB Command]->ACDB File Major = 9, ACDB File Minor = 0, ACDB File Revision = 10
02-11 12:21:02.268   617   866 D         : [ACDB Command]->SW Minor/Major/Revision version info for /vendor/etc/acdbdata/Headset_cal.acdb
02-11 12:21:02.268   617   866 D         : [ACDB Command]->ACDB Sw Major = 9, ACDB Sw Minor = 0, ACDB Sw Revision = 4, ACDB Sw Cpl Number = 0
02-11 12:21:02.268   617   866 D         : [ACDB Command]->ACDB File Major = 9, ACDB File Minor = 0, ACDB File Revision = 10
02-11 12:21:02.270   617   866 D         : [ACDB Command]->SW Minor/Major/Revision version info for /vendor/etc/acdbdata/Bluetooth_cal.acdb
02-11 12:21:02.270   617   866 D         : [ACDB Command]->ACDB Sw Major = 9, ACDB Sw Minor = 0, ACDB Sw Revision = 4, ACDB Sw Cpl Number = 0
02-11 12:21:02.270   617   866 D         : [ACDB Command]->ACDB File Major = 9, ACDB File Minor = 0, ACDB File Revision = 10
02-11 12:21:02.270   617   866 D ACDB-LOADER: ACDB -> ACPH INIT
02-11 12:21:02.271   617   866 D         : [ACPH]->Online service registered with ACPH
02-11 12:21:02.271   617   866 E Diag_Lib:  Diag_LSM_Init: Failed to open handle to diag driver, error = 13
02-11 12:21:02.271   617   866 E Diag_Lib: diag: In diagpkt_tbl_reg, service not initialized.
02-11 12:21:02.272   617   866 D         : [ACPH]->ACPH init success
02-11 12:21:02.272   617   866 D ACDB-LOADER: ACDB -> RTAC INIT
02-11 12:21:02.272   617   866 D         : [ACPH]->DSP RTC service registered with ACPH
02-11 12:21:02.272   617   866 D ACDB-LOADER: ACDB -> MCS, FTS INIT
02-11 12:21:02.273   617   866 D         : [ACPH]->MCS RTC service registered with ACPH
02-11 12:21:02.273   617   866 D         : [ACPH]->FTS RTC service registered with ACPH
02-11 12:21:02.273   617   866 D ACDB-LOADER: ACDB -> ADIE RTAC INIT
02-11 12:21:02.273   617   866 D         : [ACPH]->ADIE RTC service registered with ACPH
02-11 12:21:02.274   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOC_PROC_DYNAMIC_TABLE_SIZE
02-11 12:21:02.280   617   866 D ACDB-LOADER: ACDB -> send_common_custom_topology
02-11 12:21:02.280   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AVCS_CUSTOM_TOPO_INFO_SIZE
02-11 12:21:02.281   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AVCS_CUSTOM_TOPO_INFO
02-11 12:21:02.281   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AVCS_CUSTOM_TOPO_INFO: size:0x274 ret=0 
02-11 12:21:02.281   617   866 D ACDB-LOADER: ACDB -> CORE_CUSTOM_TOPOLOGIES
02-11 12:21:02.283   617   866 D ACDB-LOADER: ACDB -> acdb_loader_send_common_custom_topology: Common custom topology in use
02-11 12:21:02.283   617   866 D ACDB-LOADER: ACDB -> init done!
02-11 12:21:02.284   617   866 D msm8974_platform: ACDB initialized
02-11 12:21:02.285   617   866 D hardware_cal: hw_util_open: Opening device /dev/snd/hwC0D1000
02-11 12:21:02.285   617   866 D hardware_cal: hw_util_open: success
02-11 12:21:02.285   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.286   617   866 D         : Failed to fetch the lookup information of the device 0000001A 
02-11 12:21:02.286   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.286   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.286   617   866 D         : Failed to fetch the lookup information of the device 0000001A 
02-11 12:21:02.287   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.287   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.287   617   866 D         : Failed to fetch the lookup information of the device 0000001A 
02-11 12:21:02.287   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.287   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.288   617   866 D         : Failed to fetch the lookup information of the device 0000001B 
02-11 12:21:02.288   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.288   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.288   617   866 D         : Failed to fetch the lookup information of the device 0000001B 
02-11 12:21:02.289   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.289   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.289   617   866 D         : Failed to fetch the lookup information of the device 0000001B 
02-11 12:21:02.289   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.290   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.290   617   866 D         : Failed to fetch the lookup information of the device 0000001C 
02-11 12:21:02.290   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.290   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.291   617   866 D         : Failed to fetch the lookup information of the device 0000001C 
02-11 12:21:02.291   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.291   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.291   617   866 D         : Failed to fetch the lookup information of the device 0000001C 
02-11 12:21:02.291   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.292   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.292   617   866 D         : Failed to fetch the lookup information of the device 0000001D 
02-11 12:21:02.292   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.292   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.293   617   866 D         : Failed to fetch the lookup information of the device 0000001D 
02-11 12:21:02.293   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.293   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.293   617   866 D         : Failed to fetch the lookup information of the device 0000001D 
02-11 12:21:02.294   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.294   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.294   617   866 D         : Failed to fetch the lookup information of the device 0000001E 
02-11 12:21:02.294   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.294   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.295   617   866 D         : Failed to fetch the lookup information of the device 0000001E 
02-11 12:21:02.295   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.295   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.295   617   866 D         : Failed to fetch the lookup information of the device 0000001E 
02-11 12:21:02.296   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.296   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.296   617   866 D         : Failed to fetch the lookup information of the device 0000001F 
02-11 12:21:02.296   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.297   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.297   617   866 D         : Failed to fetch the lookup information of the device 0000001F 
02-11 12:21:02.297   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.297   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.298   617   866 D         : Failed to fetch the lookup information of the device 0000001F 
02-11 12:21:02.298   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.298   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.298   617   866 D         : Failed to fetch the lookup information of the device 00000067 
02-11 12:21:02.298   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.299   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.299   617   866 D         : Failed to fetch the lookup information of the device 00000067 
02-11 12:21:02.299   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.299   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.300   617   866 D         : Failed to fetch the lookup information of the device 00000067 
02-11 12:21:02.300   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.300   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.300   617   866 D         : Failed to fetch the lookup information of the device 00000056 
02-11 12:21:02.301   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.301   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.301   617   866 D         : Failed to fetch the lookup information of the device 00000056 
02-11 12:21:02.301   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.302   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.302   617   866 D         : Failed to fetch the lookup information of the device 00000056 
02-11 12:21:02.302   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.302   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.302   617   866 D         : Failed to fetch the lookup information of the device 00000059 
02-11 12:21:02.303   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.303   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.303   617   866 D         : Failed to fetch the lookup information of the device 00000059 
02-11 12:21:02.303   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.304   617   866 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_ANC_SETTING
02-11 12:21:02.304   617   866 D         : Failed to fetch the lookup information of the device 00000059 
02-11 12:21:02.304   617   866 E ACDB-LOADER: Error: ACDB ANC returned = -20
02-11 12:21:02.304   617   866 D hardware_cal: send_codec_cal cal sent for anc_cal
02-11 12:21:02.305   617   866 E ACDB-LOADER: ACDB -> send_codec_cal
02-11 12:21:02.305   617   866 E ACDB-LOADER: ACDB -> ACDB_CMD_GET_CODEC_CAL_DATA
02-11 12:21:02.305   617   866 D hardware_cal: send_codec_cal cal sent for mad_cal
02-11 12:21:02.305   617   866 D ACDB-LOADER: send mbhc data
02-11 12:21:02.306   617   866 D ACDB-LOADER: ACDB -> MBHC ACDB_PID_GENERAL_CONFIG
02-11 12:21:02.306   617   866 D ACDB-LOADER: ACDB -> MBHC ACDB_PID_PLUG_REMOVAL_DETECTION
02-11 12:21:02.306   617   866 D ACDB-LOADER: ACDB -> MBHC ACDB_PID_PLUG_TYPE_DETECTION
02-11 12:21:02.306   617   866 D ACDB-LOADER: ACDB -> MBHC ACDB_PID_BUTTON_PRESS_DETECTION
02-11 12:21:02.306   617   866 D ACDB-LOADER: ACDB -> MBHC ACDB_PID_IMPEDANCE_DETECTION
02-11 12:21:02.307   617   866 D hardware_cal: send_codec_cal cal sent for mbhc_cal
02-11 12:21:02.307   617   866 E hardware_cal: Failed to call ioctl  for  err=14
02-11 12:21:02.307   617   866 D hardware_cal: send_codec_cal cal sent for 
02-11 12:21:02.308   617   866 W msm8974_platform: init_be_dai_name_table: sound device none has no hw interface set
02-11 12:21:02.309   617   866 D msm8974_platform: init_be_dai_name_table: sound device speaker-and-headphones does not have a valid hw interface set (disregard for combo devices) SLIMBUS_0_RX-and-SLIMBUS_0_RX
02-11 12:21:02.309   617   866 D msm8974_platform: init_be_dai_name_table: sound device speaker-and-line does not have a valid hw interface set (disregard for combo devices) SLIMBUS_0_RX-and-SLIMBUS_0_RX
02-11 12:21:02.309   617   866 D msm8974_platform: init_be_dai_name_table: sound device hdmi does not have a valid hw interface set (disregard for combo devices) HDMI_RX
02-11 12:21:02.310   617   866 D msm8974_platform: init_be_dai_name_table: sound device speaker-and-hdmi does not have a valid hw interface set (disregard for combo devices) SLIMBUS_0_RX-and-HDMI_RX
02-11 12:21:02.310   617   866 D msm8974_platform: init_be_dai_name_table: sound device speaker-and-bt-a2dp does not have a valid hw interface set (disregard for combo devices) SLIMBUS_0_RX-and-SLIMBUS_7_RX
02-11 12:21:02.310   617   866 D msm8974_platform: init_be_dai_name_table: sound device speaker-safe-and-bt-a2dp does not have a valid hw interface set (disregard for combo devices) SLIMBUS_0_RX-and-SLIMBUS_7_RX
02-11 12:21:02.310   617   866 D msm8974_platform: init_be_dai_name_table: sound device voice-tx does not have a valid hw interface set (disregard for combo devices) AFE_PCM_RX
02-11 12:21:02.311   617   866 D msm8974_platform: init_be_dai_name_table: sound device speaker-and-bt-sco does not have a valid hw interface set (disregard for combo devices) SLIMBUS_0_RX-and-SEC_AUX_PCM_RX
02-11 12:21:02.311   617   866 D msm8974_platform: init_be_dai_name_table: sound device speaker-safe-and-bt-sco does not have a valid hw interface set (disregard for combo devices) QUAT_TDM_RX_0-and-SLIMBUS_7_RX
02-11 12:21:02.311   617   866 D msm8974_platform: init_be_dai_name_table: sound device speaker-and-bt-sco-wb does not have a valid hw interface set (disregard for combo devices) SLIMBUS_0_RX-and-SEC_AUX_PCM_RX
02-11 12:21:02.312   617   866 D msm8974_platform: init_be_dai_name_table: sound device speaker-safe-and-bt-sco-wb does not have a valid hw interface set (disregard for combo devices) QUAT_TDM_RX_0-and-SLIMBUS_7_RX
02-11 12:21:02.312   617   866 D msm8974_platform: init_be_dai_name_table: sound device speaker-and-usb-headphones does not have a valid hw interface set (disregard for combo devices) SLIMBUS_0_RX-and-USB_AUDIO_RX
02-11 12:21:02.312   617   866 D msm8974_platform: init_be_dai_name_table: sound device speaker-safe-and-usb-headphones does not have a valid hw interface set (disregard for combo devices) SLIMBUS_0_RX-and-USB_AUDIO_RX
02-11 12:21:02.312   617   866 W msm8974_platform: init_be_dai_name_table: sound device hdmi-mic has no hw interface set
02-11 12:21:02.313   617   866 D msm8974_platform: init_be_dai_name_table: sound device voice-rx does not have a valid hw interface set (disregard for combo devices) AFE_PCM_TX
02-11 12:21:02.313   617   866 W msm8974_platform: init_be_dai_name_table: sound device vi-feedback has no hw interface set
02-11 12:21:02.315   617   866 E ext_speaker: open_speaker_bundle: DLOPEN failed for /vendor/lib/soundfx/libspeakerbundle.so
02-11 12:21:02.319   617   866 W audio_hw_primary: adev_open: DLOPEN failed for libadm.so
02-11 12:21:02.319   617   866 D audio_hw_primary: adev_open: exit
02-11 12:21:02.319   617   866 W DeviceHAL: Error from HAL Device in function get_master_volume: Function not implemented
02-11 12:21:02.320   617   866 W DeviceHAL: Error from HAL Device in function get_master_mute: Function not implemented
02-11 12:21:02.320   617   866 W DeviceHAL: Error from HAL Device in function set_master_volume: Function not implemented
02-11 12:21:02.320   617   866 W DeviceHAL: Error from HAL Device in function set_master_mute: Function not implemented
jerpelea commented 5 years ago

@stefanhh0 please flash the latest 47.1.A.xxx.xxx

invalidsudo commented 5 years ago

@jerpelea are you sure that firmware is available on lilac?

invalidsudo commented 5 years ago

Problem persisted for me even after flashing 47.1.A.16.20.

jerpelea commented 5 years ago

did you flash a full image and boot with a SIM before flashing AOSP?

invalidsudo commented 5 years ago

@jerpelea yes.

stefanhh0 commented 5 years ago

Flashed 47.1.A.16.20, booted with inserted SIM, after that:

root@mars:/home/stefan/android/bin/current# fastboot getvar version-baseband
version-baseband: 1307-7511_47.1.A.16.20
finished. total time: 0.000s

Flashed aosp, booted and problem still there. Logfile: adb_logcat_47.1.log

Well could it be that firmware wasn't just downgraded fully as expected? Is there a way to query the real firmware versions?

jerpelea commented 5 years ago

please post dmesg

stefanhh0 commented 5 years ago

dmesg.log

invalidsudo commented 5 years ago

I cannot replicate this bug as of yesterday evening. Here's what I did:

  1. repo sync
  2. rm -rf kernel/sony/msm-4.9/common-kernel
  3. Fresh build
  4. Flashed 47.1.A.16.20 via newflasher
  5. First boot with a SIM card inserted
  6. fastboot erase userdata
  7. Flashed system.img, boot.img, vendor.img, userdata.img, TWRP, and OEM image
  8. Booted straight into AOSP. Voila!

Speakers work just fine.

stefanhh0 commented 5 years ago

Very nice, thanks! That fixed it on my phone as well, I am happy :-) So maybe the newflasher did the trick? I followed your recipe exactly, can 6. be ommited, since fastboot flash userdata userdata.img first erases as well, or is there a difference to fastboot erase userdata? Just wondering...

stefanhh0 commented 5 years ago

Upgrading to version-baseband: 1307-7511_47.2.A.8.24 and flashing aosp afterwards works as well. And even after restoring the data backup via TWRP, the speaker remains functioning.

invalidsudo commented 5 years ago

I guess something was added in between the time you built, and the time I built AOSP which fixed this issue. I just decided to go through apparently unnecessary steps in order to make sure that everything is as clean as possible.

stefanhh0 commented 5 years ago

That makes sense. Anyway flashing at least the official firmware + SIM card boot and afterwards flashing aosp was mandatory to get the speakers back online.

I've first tried the most simple approach just flashing the new aosp over the speakerless aosp-build and that didn't solve it. So the speakerless aosp-build "broke" something that could only be repaired with the firmware.