Reboot after going to suspend #2
Description
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.