search

htc-msm8960-dev / android_device_htc_m7-common

4 stars 4 forks source link

Reboot after going to suspend #2

Open zsoerenm opened 2 years ago

zsoerenm commented 2 years ago

I tried to build this ROM on my own. Everything is working fine as long as the HTC M7 is not going to suspend. So if it is connected to a PC via USB or if it is used as a Wifi hotspot this ROM works fine. However, as soon as the HTC goes to suspend (deep sleep), this build will reboot.

I tried to debug the error. These are the last lines of proc/last_kmsg:

[  241.705017] PM: suspend entry 2022-04-19 13:48:53.513601771 UTC
[  241.705017] PM: Syncing filesystems ... done.
[  241.729675] PM: Preparing system for mem sleep
[  241.730651] Freezing user space processes ... 
[  241.731658] [NFC] pn544_dev_read wait_event_interruptible breaked ret=-512
[  241.731781] [COMP][AKM8963_NST] AKECS_GetOpenStatus
[  241.733581] (elapsed 0.002 seconds) done.
[  241.733581] Freezing remaining freezable tasks ... (elapsed 0.002 seconds) done.
[  241.735839] PM: Entering mem sleep
[  241.735870] Suspending console(s) (use no_console_suspend to debug)

This isn't very informative so I set no_console_suspend to debug with:

echo N | tee /sys/module/printk/parameters/console_suspend

After unplugging the USB cable again and waiting for the HTC M7 to suspend and restart, this is the proc/last_kmsg

[  362.074218] [BATT] power_supply_changed: battery at 362070859487 (2022-04-19 13:55:16.882040423 UTC)
[  362.074279] [BATT] batt_worker: done
[  369.426208] [BATT][CHG] chg_gone=1, usb_valid=1, dc_valid=0, fsm=7
[  369.427001] [BATT][CHG] usbin_valid_irq_handler: usb_target_ma=0, usb_aicl_max_ma=0, is_vin_min_detected=0
[  369.427032] [CABLE] cable_detection_vbus_irq_handler
[  369.427032] [CABLE] cable_detection_vbus_irq_handler --
[  369.428863] [BATT][BMS] end_percent=100%, last_charge_increase=0, last_chargecycles=0, 
[  369.440765] [BATT][CHG] chg_gone=0, usb_valid=0, dc_valid=0, fsm=3
[  369.523468] [BATT][CHG] pm8921_is_pwr_src_plugged_in: usb_in=0, dc_in=0
[  369.523468] [CABLE] check_vbus_in: vbus = 1, vbus_in = 0
[  369.523498] [USBH] msm_otg_set_vbus_state: 0
[  369.523498] [USB] PMIC: BSV clear
[  369.523529] [USBH] msm_otg_sm_work: state:b_peripheral bit:0x00000001
[  369.523529] [USB] b_peripheral work
[  369.523529] [USB] OTG_STATE_B_PERIPHERAL state
[  369.523559] [USBH] !id  || id_a/b || !b_sess_vld
[  369.523559] [USB] Avail curr from USB = 0
[  369.523559] [USB] Power Supply doesn't support USB charger
[  369.523590] [BATT][CHG] Enter charge=0 (deprecated api)
[  369.523590] [USBH] gadget off
[  369.523712] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_DISCONNECT_EVENT received
[  369.523803] [USBH] send connect type 0
[  369.523834] [CABLE] usb_status_notifier_func: cable_type = 0
[  369.523864] [CABLE] send_cable_connect_notify: cable_type = 0
[  369.523895] [CABLE] Send to: htc_battery_8960, type 0
[  369.523895] [BATT] cable_status_notifier_func(0) at 369520566514 (2022-04-19 13:55:24.331716932 UTC)
[  369.523986] android_work: android_work: sent uevent USB_STATE=DISCONNECTED
[  369.524047] [BATT] No cable exists at 369520719101 (2022-04-19 13:55:24.331869520 UTC)
[  369.524108] [BATT] htc_charger_event_notify charger event=3
[  369.524169] [BATT] batt_worker: total_time since last batt update = 7500 ms. at 369520810654 (2022-04-19 13:55:24.331961073 UTC)
[  369.524383] [BATT][BMS] cc_uah = 1090uAh, raw->cc = 3e617, cc = 255511 after subtracting 0
[  369.533599] [HS_MGR] (usb_headset_detect) Remove USB_HEADSET (state 0, 0) (04-19 13:55:24.341)
[  369.533630] [USBH] msm_otg_sm_work: state:b_idle bit:0x00000001
[  369.533660] [USB] b_idle work
[  369.533660] [USB] OTG_STATE_B_IDLE state
[  369.533660] [USB] chg_work cancel
[  369.533660] [USBH] !b_sess_vld && id
[  369.533691] [USBH] msm_otg_reset
[  369.533813] [USBH] phy_reset: success
[  369.534973] [BATT][BMS] FCC=2300000,UC=115000,RC=2300000,CC=1091,CC_reset=0,RUC=2183909,SOC=100,SOC_R=2075900,start_percent=-22,end_percent=-22,OCV=4307116,OCV_raw=4322116,rbatt=307,rbatt_sf=123,batt_temp=249,soc_rbatt=99,last_rbatt=-22,V_unusable_uv=3614000,pc_unusable=5,rc_pc=100,scalefactor=100,no_ocv_update_ms=367850,consistent=0
[  369.535034] [BATT][BMS] pm8921_bms_get_batt_soc: state_of_charge=100, store_soc_ui=100, last_good_ocv_uv=4307116, raw.cc=255666, stored_cc_uv:255666, currtime_ms=1109082663
[  369.535186] [BATT] batt_level_adjust: Cable plug out when level 100, reset timer. at 369531858018 (2022-04-19 13:55:24.343008436 UTC)
[  369.535247] [BATT] set_pwrsrc_and_charger_enable(0, 0, 0) at 369531919053 (2022-04-19 13:55:24.343069471 UTC)
[  369.535308] [BATT][CHG] src=0, chg_enable=0, pwrsrc_enable=0, screen_state=1, mfg_mode=0, usb_aicl_max_ma=0, is_vin_min_detected=0
[  369.537109] [BATT][CHG] pm8921_apply_19p2mhz_kickstart
[  369.538299] [BATT][CHG] vbus present change: 1 -> 0
[  369.539215] [BATT][CHG] Set vbatdet=5780 after cable out
[  369.566711] [BATT][CHG] V=4288 mV, I=140 mA, T=24 C, SoC=100%, FCC=2300000, id=126 mV, H=1, P=1, CHG=1, S=2, FSM=3, AC=0, USB=0, DC=0, WLC=0 iusb_ma=100, usb_target_ma=0, OVP=0, UVP=0, TM=0, eoc_count/by_curr=0/0, vbatdet_low=1, is_ac_ST=0, batfet_dis=0x2, pwrsrc_dis=0x1, is_full=0, temp_fault=0, is_bat_warm/cool=0/0, btm_warm/cool=0/0, ichg=0 uA, vph_pwr=4288143 uV, usbin=0 uV, dcin=0 uV, pwrsrc_under_rating=0, usbin_critical_low_cnt=0, disable_reverse_boost_check=0, flag=0000, hsml_target_ma=0, vin_min=4400, pj_exist=0
[  369.569671] [BATT] ID=2,level=100,level_raw=100,vol=4244,temp=249,current=269100,chg_src=0,chg_en=0,pj_src=0,pj_level=0,full_bat=2300,over_vchg=0,batt_state=1,overload=0,ui_chg_full=0 at 369566342882 (2022-04-19 13:55:24.377462783 UTC)
[  369.570922] [BATT] power_supply_changed: battery at 369567563585 (2022-04-19 13:55:24.378744521 UTC)
[  369.571197] [BATT] power_supply_changed: usb at 369567838243 (2022-04-19 13:55:24.379019179 UTC)
[  369.571228] [BATT] batt_worker: done
[  369.593170] [LED]pm8xxx_led_set +++
[  369.593231] [LED]pm8xxx_led_set ---
[  369.593475] [LED]pm8xxx_led_current_set, bank:6, brightness:255 +++
[  369.593811] [LED]pm8xxx_led_current_set, bank:6, brightness:255 ---
[  369.608551] [BATT][CHG] Stopping Unplug Check - chargers are removedreg_loop = 9, fsm = 3 ibat = 223000 (rb_trial_count=0 ovp_trial_count=0)
[  369.608581] [BATT][CHG] pm8921_apply_19p2mhz_kickstart
[  369.629180] [DISP] mipi_dsi_panel_power: on=1
[  369.643737] [USBH] ulpi: write 0x37 to 0x81
[  369.643737] [USBH] ulpi: write 0x3c to 0x82
[  369.643768] [USB] OTG runtime suspend
[  369.643798] [USBH] msm_otg_suspend
[  369.645080] [USBH] msm_hsusb_ldo_enable: hsusb_1p8: 0uA
[  369.645080] [USBH] reg (LPM)
[  369.645080] [USBH] msm_hsusb_config_vddcx: min_vol:0 max_vol:1320000
[  369.645111] [USBH] USB in low power mode
[  369.804443] [BATT][CHG] Stopping Unplug Check - chargers are removedreg_loop = 9, fsm = 3 ibat = 717100 (rb_trial_count=0 ovp_trial_count=0)
[  369.804473] [BATT][CHG] pm8921_apply_19p2mhz_kickstart
[  369.827728] [TP] synaptics_ts_resume: enter
[  369.830200] [TP] synaptics_ts_resume: Enable P-sensor by Touch
[  369.830230] [TP] psensor status 0 -> 1
[  369.848297] [WLAN] wl_android_priv_cmd: Android private cmd "SETSUSPENDMODE 0" on wlan0
[  369.848297] [WLAN] dhd_set_suspend: enter, value = 0 in_suspend=0
[  369.848327] [WLAN] wl_android_set_screen_off 0
[  369.851196] [TP] psensor status 1 -> 3
[  369.851257] [TP] synaptics_ts_close_psensor_func: Disable P-sensor by Touch
[  369.852325] hdmi_msm hdmi_msm.1: hdmi_common_wta_hpd: '0'
[  369.852478] set_tfa9887_spkamp: en = 1 dsp_enabled = 1
[  369.860260] set_tfa9887l_spkamp: en = 1 dsp_enabled = 1
[  369.861450] [TP] psensor status 3 -> 0
[  369.865051] mdp4_overlay_mdp_perf_upd mdp clk is changed [1] from 0 to 160000000
[  369.887481] ACDB=> get_hw_delay Invalid delay/ delay entries
[  369.887481] ACDB=> get_hw_delay: Path = 0 samplerate = 48000 usec = 2684354835 status -22
[  369.895172] [WLAN] wl_cfg80211_dhd_chk_link wl_get_drv_status(wl, CONNECTED, dev) = 0
[  369.895202] [WLAN] update pm: PM_FAST, wifiLock: 1
[  369.898071] [WLAN] update dtim listern interval: 0
[  369.898864] [WLAN] dhd_set_keepalive set result ret[0]
[  369.898864] [WLAN] dhd_enable_packet_filter: enter, value = 0, multicast_lock = 1, is_screen_off= 0
[  369.899749] [WLAN] dhd_pktfilter_offload_enable: successfully disable pktfilter 100 0 0 0 0x01 0x00
[  370.003509] [BATT][CHG] update_ovp_uvp_state_by_cable_irq, ovp=0, uvp=0, cable_in_irq=1, ov=1, v=0, uv=1
[  372.025177] [BATT][CHG] eoc_worker: End due to fast_chg=0
[  375.688507] set_tfa9887_spkamp: en = 0 dsp_enabled = 1
[  375.690551] set_tfa9887l_spkamp: en = 0 dsp_enabled = 1
[  375.706359] [LED]pm8xxx_led_set +++
[  375.706359] [LED]pm8xxx_led_set ---
[  375.706420] [LED]pm8xxx_led_current_set, bank:6, brightness:0 +++
[  375.706665] [LED]pm8xxx_led_current_set, bank:6, brightness:0 ---
[  429.603729] [BATT] batt_worker: total_time since last batt update = 60080 ms. at 429600369979 (2022-04-19 13:56:24.411520397 UTC)
[  429.603942] [BATT][BMS] cc_uah = 3475uAh, raw->cc = c6b52, cc = 813906 after subtracting 0
[  429.616760] [BATT][BMS] FCC=2300000,UC=115000,RC=2300000,CC=3476,CC_reset=0,RUC=2181524,SOC=100,SOC_R=1837400,start_percent=-22,end_percent=-22,OCV=4307116,OCV_raw=4322116,rbatt=307,rbatt_sf=123,batt_temp=249,soc_rbatt=99,last_rbatt=-22,V_unusable_uv=3614000,pc_unusable=5,rc_pc=100,scalefactor=100,no_ocv_update_ms=427940,consistent=0
[  429.616790] [BATT][BMS] pm8921_bms_get_batt_soc: state_of_charge=100, store_soc_ui=100, last_good_ocv_uv=4307116, raw.cc=814283, stored_cc_uv:814283, currtime_ms=1109142752
[  429.616882] [BATT] batt_level_adjust: Cable plug out, to store difference between UI & SOC. store_level:0, prev_level:100, prev_raw_level:100 at 429613553573 (2022-04-19 13:56:24.424703992 UTC)
[  429.616912] [BATT] remap: no soc drop and no additional 1%, ui:100%
[  429.628082] [TP] synaptics_ts_suspend: enter
[  429.628814] [BATT][CHG] V=4199 mV, I=514 mA, T=24 C, SoC=100%, FCC=2300000, id=118 mV, H=1, P=1, CHG=1, S=2, FSM=3, AC=0, USB=0, DC=0, WLC=0 iusb_ma=100, usb_target_ma=0, OVP=0, UVP=0, TM=0, eoc_count/by_curr=0/0, vbatdet_low=1, is_ac_ST=0, batfet_dis=0x2, pwrsrc_dis=0x1, is_full=0, temp_fault=0, is_bat_warm/cool=0/0, btm_warm/cool=0/0, ichg=0 uA, vph_pwr=4184574 uV, usbin=0 uV, dcin=0 uV, pwrsrc_under_rating=0, usbin_critical_low_cnt=0, disable_reverse_boost_check=0, flag=0000, hsml_target_ma=0, vin_min=4400, pj_exist=0
[  429.628845] [BATT] ID=2,level=100,level_raw=100,vol=4198,temp=250,current=368000,chg_src=0,chg_en=0,pj_src=0,pj_level=0,full_bat=2300,over_vchg=0,batt_state=1,overload=0,ui_chg_full=0 at 429625516464 (2022-04-19 13:56:24.436666883 UTC)
[  429.628875] [BATT] power_supply_changed: battery at 429625516464 (2022-04-19 13:56:24.436697400 UTC)
[  429.628906] [BATT] batt_worker: done
[  429.750305] [DISP] mipi_dsi_panel_power: on=0
[  429.934387] [WLAN] wl_android_priv_cmd: Android private cmd "SETSUSPENDMODE 1" on wlan0
[  429.934387] [WLAN] dhd_set_suspend: enter, value = 1 in_suspend=1
[  429.934387] [WLAN] wl_android_set_screen_off 1
[  429.937744] [WLAN] dhd_set_keepalive set result ret[0]
[  429.937744] [WLAN] dhd_enable_packet_filter: enter, value = 0, multicast_lock = 1, is_screen_off= 1
[  429.939819] [WLAN] dhd_pktfilter_offload_enable: successfully disable pktfilter 100 0 0 0 0x01 0x00
[  429.943145] [WLAN] update pm: PM_FAST, wifiLock: 0
[  429.946075] [WLAN] Clear KDDI APK bit when screen off
[  429.946075] [WLAN] update pm: PM_FAST, wifiLock: 0
[  429.955993] [WLAN] update dtim listern interval: 3
[  429.961242] [WLAN] set traffic = 0 and relase performace lock when screen off
[  430.049133] active wakeup source: msm_hsic_host
[  432.225341] PM: suspend entry 2022-04-19 13:56:27.033163473 UTC
[  432.225372] PM: Syncing filesystems ... done.
[  432.261749] PM: Preparing system for mem sleep
[  432.262878] Freezing user space processes ... 
[  432.264129] [COMP][AKM8963_NST] AKECS_GetOpenStatus
[  432.264312] [NFC] pn544_dev_read wait_event_interruptible breaked ret=-512
[  432.266021] (elapsed 0.003 seconds) done.
[  432.266052] Freezing remaining freezable tasks ... (elapsed 0.002 seconds) done.
[  432.268188] PM: Entering mem sleep
[  432.271148] [BATT] htc_battery_prepare: passing time:2660 ms, alarm will be triggered after 3598 sec.(suspend_highfreq_check_reason=0x0, htc_batt_info.state=0x4), batt_temp=249, sensor0_temp=0 at 432267819941 (2022-04-19 13:56:27.078970359 UTC)
[  432.273345] msm_fb_ext_suspend: Turning off HPD circuitry
[  432.275726] [GYRO][R3GD20] r3gd20_suspend++: data->is_suspended = 1
[  432.275756] [GYRO][R3GD20] polling disabled
[  432.277252] [GYRO][R3GD20] r3gd20_suspend:--
[  432.278259] [GSNR][BMA250_BOSCH] bma250_suspend++
[  432.278289] [GSNR][BMA250_BOSCH] bma250_suspend--
[  432.278289] [FLT]TPS tps61310_suspend:
[  432.278289] [FLT]TPS flashlight_turn_off
[  432.279754] [CIR] msm_serial_hsl_suspend ():port->line 2, cir_enable_flg = 2
[  432.279754] [CIR] msm_serial_hsl_suspend ():is_console:port->line 2, ir
[  432.279785] [CIR] cir_power on = 0, reg_cir_3v = 0xeedccb00
[  432.280761] [CIR] cir_power(off): success
[  432.293579] [USB] OTG PM suspend
[  432.293670] [LED] led_power_LPM: enter:1
[  432.293762] 8921_l29: Failed to create debugfs directory
[  432.294952] [LED] led_power_LPM: enter LMP mode
[  432.295166] [BATT][BMS] cc_uah = 3638uAh, raw->cc = d0063, cc = 852067 after subtracting 0
[  432.295166] [BATT][BMS] pm8921_bms_suspend: BMS_TOLERANCES=0x0f
[  432.295593] PM: suspend of devices complete after 23.498 msecs
[  432.296325] PM: late suspend of devices complete after 0.701 msecs
[  432.298461] [BATT][CHG] pm8921_apply_19p2mhz_kickstart
[  432.299255] PM: noirq suspend of devices complete after 2.929 msecs
[  432.299255] Disabling non-boot CPUs ...
[  432.345062] msm_pm_enter
[  432.345062] msm_pm_enter: power collapse
[  432.345062] msm_mpm_irqs_detectable: cannot monitor irq=261 (null)
[  432.345062] msm_pm_enter: return
[  432.345153] Enabling non-boot CPUs ...
[  432.348907] CPU1 is up
[  432.360748] CPU2 is up
[  432.373596] CPU3 is up
[  432.374694] [BATT][CHG] pm8921_apply_19p2mhz_kickstart
[  432.376098] PM: noirq resume of devices complete after 2.471 msecs
[  432.377929] PM: early resume of devices complete after 0.457 msecs
[  432.378479] [BATT][BMS] cc_uah = 3657uAh, raw->cc = d1287, cc = 856711 after subtracting 0
[  432.378509] [BATT][BMS] pm8921_bms_resume: BMS_TOLERANCES=0x0f
[  432.378540] [LED] led_power_LPM: enter:0
[  432.379333] [LED] led_power_LPM: leave LMP mode
[  432.381866] [USB] OTG PM resume
[  432.393005] [CIR] msm_serial_hsl_resume ():port->line 2, cir_enable_flg = 2
[  432.393035] [CIR] cir_power on = 1, reg_cir_3v = 0xeedccb00
[  432.393920] [CIR] cir_power(on): success
[  432.394042] [FLT]TPS tps61310_resume:
[  432.394073] [GSNR][BMA250_BOSCH] bma250_resume++
[  432.394073] [GYRO][R3GD20] r3gd20_resume:++
[  432.394104] [GYRO][R3GD20] r3gd20_resume--: data->is_suspended = 0
[  432.395690] msm_fb_ext_resume: Turning on HPD circuitry
[  432.396301] PM: resume of devices complete after 18.362 msecs
[  432.401824] [BATT] htc_battery_complete: sr_time_period=124 ms; total passing time=2784 ms.htc_batt_info.state=0x0, batt_temp=234, sensor0_temp=0 at 432398451201 (2022-04-19 13:56:27.209601643 UTC)
[  432.402099] PM: Finishing wakeup.
[  432.402099] Restarting tasks ... 
[  432.403900] [COMP][AKM8963_NST] AKECS_GetOpenStatus++
[  432.406158] done.
[  432.406219] PM: suspend exit 2022-04-19 13:56:27.213962043 UTC
[  432.508087] PM: suspend entry 2022-04-19 13:56:27.315787103 UTC
[  432.508117] PM: Syncing filesystems ... done.
[  432.514892] PM: Preparing system for mem sleep
[  432.562408] Freezing user space processes ... 
[  432.563720] [NFC] pn544_dev_read wait_event_interruptible breaked ret=-512
[  432.564056] [COMP][AKM8963_NST] AKECS_GetOpenStatus
[  432.565887] (elapsed 0.003 seconds) done.
[  432.565917] Freezing remaining freezable tasks ... (elapsed 0.002 seconds) done.
[  432.568054] PM: Entering mem sleep
[  432.571014] [BATT] htc_battery_prepare: passing time:2954 ms, alarm will be triggered after 3598 sec.(suspend_highfreq_check_reason=0x0, htc_batt_info.state=0x4), batt_temp=233, sensor0_temp=0 at 432567524189 (2022-04-19 13:56:27.378674625 UTC)
[  432.574340] msm_fb_ext_suspend: Turning off HPD circuitry
[  432.576660] [GYRO][R3GD20] r3gd20_suspend++: data->is_suspended = 1
[  432.576660] [GYRO][R3GD20] polling disabled
[  432.577941] [GYRO][R3GD20] r3gd20_suspend:--
[  432.579010] [GSNR][BMA250_BOSCH] bma250_suspend++
[  432.579040] [GSNR][BMA250_BOSCH] bma250_suspend--
[  432.579071] [FLT]TPS tps61310_suspend:
[  432.579101] [FLT]TPS flashlight_turn_off
[  432.579833] [CIR] msm_serial_hsl_suspend ():port->line 2, cir_enable_flg = 2
[  432.579864] [CIR] msm_serial_hsl_suspend ():is_console:port->line 2, ir
[  432.579895] [CIR] cir_power on = 0, reg_cir_3v = 0xeedccb00
[  432.580963] [CIR] cir_power(off): success
[  432.600311] [USB] OTG PM suspend
[  433.335021] [LED] led_power_LPM: enter:1
[  433.336090] [LED] led_power_LPM: enter LMP mode
[  433.336395] [BATT][BMS] cc_uah = 3680uAh, raw->cc = d26c3, cc = 861891 after subtracting 0
[  433.336456] [BATT][BMS] pm8921_bms_suspend: BMS_TOLERANCES=0x0f
[  433.337432] PM: suspend of devices complete after 765.194 msecs
[  433.339233] PM: late suspend of devices complete after 1.769 msecs
[  433.343017] [BATT][CHG] pm8921_apply_19p2mhz_kickstart
[  433.343994] PM: noirq suspend of devices complete after 4.728 msecs
[  433.344024] Disabling non-boot CPUs ...
[  433.402465] msm_pm_enter
[  433.402465] msm_pm_enter: power collapse
[  433.402465] msm_mpm_irqs_detectable: cannot monitor irq=261 (null)

It tries to go to suspend twice. I cannot see a clear error except msm_mpm_irqs_detectable: cannot monitor irq=261 (null). How would you debug this @TARKZiM ? I would be happy to dive deeper to get this device working.

zsoerenm commented 2 years ago

I observed something interesting: I rooted the devices with Magisk and installed Kernel Adiutor. If I disable all cores excepts the first one, the M7 won't reboot, when going to suspend. Any hints to resolve this issue will be appreciated.

zsoerenm commented 2 years ago

I finally found the error. mpdecision could not start correctly, due to sepolicy. I tried to start mpdecision manually with start mpdecision and the dmesg output was the following:

init: Control message: Could not ctl.start for 'mpdecision' from pid: 2741 (start mpdecision): File /system/bin/mpdecision (labeled "u:object_r:system_file:s0") has incorrect label or no domain transition from u:r:init:s0 to another SELinux domain defined. Have you configured your service correctly? https://source.android.com/security/selinux/device-policy#label_new_services_and_address_denials

I set selinux to permissive and now it isn't rebooting anymore. @TARKZiM do you know how to set the sepolicy correctly?