[4.19][AOSP11][pdx203/Edo] Modem crashes shortly after boot

[Thaodan]

Platform: Edo Device: Xperia 1 II/PDX203 Kernel version: 4.19 Android version: 11.0.0_r46 Software binaries version: v8a

Previously working on None that I know of.

Description When the device suspends/screen of the modem crashes after a time resulting in a kernel panic

Symptoms kernel panic

How to reproduce Start device, put screen of, wait a few seconds.

Additional context Device did not had any simcard inserted.

console-ramoops-0.log . dmesg-ramoops-0.log dmesg-ramoops-1.log

[Thaodan]

12-08 20:56:29.814  4118  4118 E QTI_SDM_INFO: [qti_rmnet_modem.c:1225] qti_rmnet_modem_recv_msg():Failed to read from the dev file. Errno 512 error msg=Unknown error 512
12-08 20:56:29.814  4118  4118 I QTI_SDM_INFO: [qti_rmnet_modem.c:267] qti_rmnet_fusion_modem_handle():Received QMUXD cb event id 0
12-08 20:56:29.814  4118  4118 I QTI_SDM_INFO: [qti_rmnet_modem.c:1075] qti_rmnet_modem_reset():Closing the modem fd 
12-08 20:56:29.814  4118  4118 I QTI_SDM_INFO: [qti_rmnet_peripheral.c:1246] qti_rmnet_ph_set_modem_state():Received set modem state to 0
12-08 20:56:29.814  4118  4118 E QTI_SDM_INFO: [qti_rmnet_peripheral.c:1258] qti_rmnet_ph_set_modem_state():Couldn't set ph_iface_fd
12-08 20:56:29.814  4118  4118 E QTI_SDM_INFO: [qti_rmnet_modem.c:283] qti_rmnet_fusion_modem_handle():Failed to set modem state on peripheral driver file
12-08 20:56:29.814  4118  4118 E QTI_SDM_INFO: [qti_rmnet_modem.c:296] qti_rmnet_fusion_modem_handle():No peripheral is enabled
12-08 20:56:29.814  4118  4118 I QTI_SDM_INFO: [qti_rmnet_modem.c:1220] qti_rmnet_modem_recv_msg():Read -1 data from modem device file
12-08 20:56:29.814  4118  4118 E QTI_SDM_INFO: [qti_rmnet_modem.c:1225] qti_rmnet_modem_recv_msg():Failed to read from the dev file. Errno 9 error msg=Bad file descriptor
12-08 20:56:33.195  4175  4190 I mdm_helper: SDX55M: Recieved request to transfer images
12-08 20:56:33.195  4175  4190 I mdm_helper: SDX55M : switching state to SAHARA:
12-08 20:56:33.195  4175  4190 I mdm_helper: SDX55M: Beginning sahara image transfer.
12-08 20:56:33.195  4175  4190 I mdm_helper: Wrote to /sys/power/wake_lock
12-08 20:56:33.195  4175  4190 I libmdmimgload: MDM name 'SDX55M', Link type 'PCIe'
12-08 20:56:33.195  4175  4190 I libmdmimgload: Using sahara mapping for SDX55M
12-08 20:56:33.195  4175  4190 I libmdmimgload: Testing if file(port) "/dev/mhi_0306_02.01.00_pipe_2" exists
12-08 20:56:38.222  4175  4190 E libmdmimgload: '/dev/mhi_0306_02.01.00_pipe_2' was not found in first 5 seconds. Retrying..

This is what happens if I unplug the device.

[Thaodan]

I'm not sure but someone had a log here with similar output: https://community.sony.co.uk/t5/1-series/xperia-1-ii-loses-4g-connection-in-telenor-bulgaria-s-network/td-p/3702473/page/2

[Thaodan]

There are other errors regarding modem in dmesg;

Dec 08 23:07:30 xqat51 kernel: sec_ts 5-0048: [sec_input] failed to unlock power
Dec 08 23:07:31 xqat51 kernel: ext-mdm soc:qcom,mdm0: mdm_errfatal: mdm sent errfatal interrupt
Dec 08 23:07:31 xqat51 kernel: [E][mhi_control_error] mhi:esoc0 sfr: 0xffffff8008015000
Dec 08 23:07:33 xqat51 kernel: ext-mdm soc:qcom,mdm0: unexpected reset external modem
Dec 08 23:07:33 xqat51 kernel: unable to queue event for SDX55M
Dec 08 23:07:33 xqat51 kernel: subsys-restart: subsystem_restart_dev(): Restart sequence requested for esoc0, restart_level = RELATED.
Dec 08 23:07:33 xqat51 kernel: subsys-restart: subsystem_shutdown(): [kworker/u17:16:4354]: Shutting down esoc0
Dec 08 23:07:33 xqat51 kernel: sysmon-qmi: ssctl_del_server: Connection lost between QMI handle and esoc0's SSCTL service
Dec 08 23:07:33 xqat51 kernel: ------------[ cut here ]------------
Dec 08 23:07:33 xqat51 kernel: workqueue: WQ_MEM_RECLAIM mhi_w:mhi_pm_st_worker is flushing !WQ_MEM_RECLAIM events_highpri:flush_backlog
Dec 08 23:07:33 xqat51 kernel: WARNING: CPU: 2 PID: 4353 at kernel/workqueue.c:2530 check_flush_dependency+0xd4/0x120
Dec 08 23:07:33 xqat51 kernel: Modules linked in:
Dec 08 23:07:33 xqat51 kernel: CPU: 2 PID: 4353 Comm: kworker/u17:15 Tainted: G S      W         4.19.188-g4114118d4df6-dirty #8
Dec 08 23:07:33 xqat51 kernel: Hardware name: Sony Mobile Communications. PDX-203(KONA) (DT)
Dec 08 23:07:33 xqat51 kernel: Workqueue: mhi_w mhi_pm_st_worker
Dec 08 23:07:33 xqat51 kernel: pstate: 60c00085 (nZCv daIf +PAN +UAO)
Dec 08 23:07:33 xqat51 kernel: pc : check_flush_dependency+0xd4/0x120
Dec 08 23:07:33 xqat51 kernel: lr : check_flush_dependency+0xd4/0x120
Dec 08 23:07:33 xqat51 kernel: sp : ffffff800e0ab800
Dec 08 23:07:33 xqat51 kernel: x29: ffffff800e0ab800 x28: ffffff801f20b0d8 
Dec 08 23:07:33 xqat51 kernel: x27: ffffff801f20af60 x26: ffffffa7f56b0870 
Dec 08 23:07:33 xqat51 kernel: x25: 0000000000000003 x24: ffffffd8f9964c80 
Dec 08 23:07:33 xqat51 kernel: x23: 0000000000000001 x22: ffffffd8f9969f00 
Dec 08 23:07:33 xqat51 kernel: x21: ffffffa7f3d670b0 x20: ffffffd8b8f88600 
Dec 08 23:07:33 xqat51 kernel: x19: ffffffd78681fa00 x18: ffffffffffffffff 
Dec 08 23:07:33 xqat51 kernel: x17: 0000000000000000 x16: ffffffa7f59209a0 
Dec 08 23:07:33 xqat51 kernel: x15: ffffffa875922797 x14: 4345525f4d454d5f 
Dec 08 23:07:33 xqat51 kernel: x13: 51572120676e6968 x12: 73756c6620736920 
Dec 08 23:07:33 xqat51 kernel: x11: 72656b726f775f74 x10: 735f6d705f69686d 
Dec 08 23:07:33 xqat51 kernel: x9 : 3a775f69686d204d x8 : 0000000000000080 
Dec 08 23:07:33 xqat51 kernel: x7 : 73756c663a697270 x6 : ffffffa7f59222b9 
Dec 08 23:07:33 xqat51 kernel: x5 : 0000000000000000 x4 : 0000000000000000 
Dec 08 23:07:33 xqat51 kernel: x3 : ffffffffffffffff x2 : 0000000000000000 
Dec 08 23:07:33 xqat51 kernel: x1 : 0000000000000000 x0 : ffffffa7f560d000 
Dec 08 23:07:33 xqat51 kernel: Call trace:
Dec 08 23:07:33 xqat51 kernel:  check_flush_dependency+0xd4/0x120
Dec 08 23:07:33 xqat51 kernel:  __flush_work+0x1c8/0x260
Dec 08 23:07:33 xqat51 kernel:  flush_work+0x10/0x20
Dec 08 23:07:33 xqat51 kernel:  rollback_registered_many+0x1d0/0x5dc
Dec 08 23:07:33 xqat51 kernel:  rollback_registered+0x60/0xb0
Dec 08 23:07:33 xqat51 kernel:  unregister_netdevice_queue+0x90/0x120
Dec 08 23:07:33 xqat51 kernel:  unregister_netdev+0x20/0x30
Dec 08 23:07:33 xqat51 kernel:  mhi_netdev_remove+0x50/0x1fc
Dec 08 23:07:33 xqat51 kernel:  mhi_driver_remove+0x17c/0x390
Dec 08 23:07:33 xqat51 kernel:  __device_release_driver+0x16c/0x20c
Dec 08 23:07:33 xqat51 kernel:  device_release_driver+0x28/0x40
Dec 08 23:07:33 xqat51 kernel:  bus_remove_device+0x118/0x124
Dec 08 23:07:33 xqat51 kernel:  device_del+0x168/0x3c4
Dec 08 23:07:33 xqat51 kernel:  mhi_destroy_device+0x58/0x90
Dec 08 23:07:33 xqat51 kernel:  device_for_each_child+0x5c/0xb0
Dec 08 23:07:33 xqat51 kernel:  mhi_pm_st_worker+0x55c/0xbe0
Dec 08 23:07:33 xqat51 kernel:  process_one_work+0x1a4/0x41c
Dec 08 23:07:33 xqat51 kernel:  worker_thread+0x200/0x410
Dec 08 23:07:33 xqat51 kernel:  kthread+0x134/0x160
Dec 08 23:07:33 xqat51 kernel:  ret_from_fork+0x10/0x24
Dec 08 23:07:33 xqat51 kernel: ---[ end trace 528acf6bfd16f914 ]---
Dec 08 23:07:33 xqat51 kernel: rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_mhi0
Dec 08 23:07:33 xqat51 kernel: rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister
Dec 08 23:07:33 xqat51 kernel: rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data0
Dec 08 23:07:33 xqat51 kernel: rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data1
Dec 08 23:07:33 xqat51 kernel: rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data2
Dec 08 23:07:33 xqat51 kernel: rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data3
Dec 08 23:07:33 xqat51 kernel: rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data4
Dec 08 23:07:33 xqat51 kernel: rmnet_shs deinit rmnet_data5 going down 
Dec 08 23:07:33 xqat51 kernel: rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data5
Dec 08 23:07:33 xqat51 kernel: rmnet_ctl driver removed
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: Read of RC2 1:0x00 + 0x0060[4] is all FFs
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
Dec 08 23:07:33 xqat51 kernel: msm_pcie_disable: PCIe: Assert the reset of endpoint of RC2.
Dec 08 23:07:33 xqat51 kernel: IRQ 5: no longer affine to CPU5
Dec 08 23:07:36 xqat51 kernel: subsys-restart: subsystem_powerup(): [kworker/u17:16:4354]: Powering up esoc0
Dec 08 23:07:37 xqat51 kernel: msm_pcie_enable: PCIe: Assert the reset of endpoint of RC2.
Dec 08 23:07:37 xqat51 kernel: msm_pcie_enable: PCIe: RC2: PCIE20_PARF_INT_ALL_MASK: 0x7f80d202
Dec 08 23:07:37 xqat51 kernel: pcie_phy_init: PCIe RC2 PHY is ready!
Dec 08 23:07:37 xqat51 kernel: msm_pcie_enable: PCIe: Release the reset of endpoint of RC2.
Dec 08 23:07:37 xqat51 kernel: msm_pcie_link_train: PCIe RC2 link initialized
Dec 08 23:07:37 xqat51 kernel: mhi 0002:01:00.0: BAR 0: assigned [mem 0x64300000-0x64300fff 64bit]
Dec 08 23:07:37 xqat51 kernel: mhi 0002:01:00.0: enabling device (0000 -> 0002)
Dec 08 23:07:37 xqat51 kernel: [E][mhi_init_pci_dev] Failed to enable MSI, ret:-28
Dec 08 23:07:40 xqat51 kernel: incell_power_lock: Lock is invalid during power off
Dec 08 23:07:40 xqat51 kernel: sec_ts 5-0048: [sec_input] power lock failed ret:-1
Dec 08 23:07:40 xqat51 kernel: sec_ts 5-0048: [sec_input] failed to lock power
Dec 08 23:07:40 xqat51 kernel: incell_power_unlock: Power state already unlocked
Dec 08 23:07:40 xqat51 kernel: sec_ts 5-0048: [sec_input] power lock failed ret:-3
Dec 08 23:07:40 xqat51 kernel: sec_ts 5-0048: [sec_input] failed to unlock power
Dec 08 23:07:40 xqat51 kernel: pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
Dec 08 23:07:40 xqat51 kernel: FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 46 but ignore this function
Dec 08 23:07:40 xqat51 kernel: ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:7721

[Thaodan]

Full logcat when it happens logcat_modem_crash_edo.log

[bartcubbins]

please try the latest v8 binaries https://developer.sony.com/file/download/software-binaries-for-aosp-android-11-0-kernel-4-19-edo/

[Thaodan]

please try the latest v8 binaries https://developer.sony.com/file/download/software-binaries-for-aosp-android-11-0-kernel-4-19-edo/

The test was done using those binaries, just forgot to update the info. Fixed now.

[jerpelea]

@Thaodan ps -A | grep ks ps -A | grep msm_helper

[Thaodan]

@jerpelea

[root@xqat51 defaultuser]# ps -A | grep ks
   10 root     [ksoftirqd/0]
   24 root     [ksoftirqd/1]
   33 root     [ksoftirqd/2]
   42 root     [ksoftirqd/3]
   51 root     [ksoftirqd/4]
   60 root     [ksoftirqd/5]
   69 root     [ksoftirqd/6]
   78 root     [ksoftirqd/7]
   86 root     [rcu_tasks_kthre]
  103 root     [kswapd-1:0]
  327 root     [ufs_clkscaling_]
 7805 root     grep ks
[root@xqat51 defaultuser]# ps -A | grep msm_helper
 8253 root     grep msm_helper

[Thaodan]

ks is later tun as:

12-09 07:57:46.459  4206  4220 E libmdmimgload: Running '/odm/bin/ks -o -p /dev/mhi_0306_02.01.00_pipe_2 -w /data/vendor/tombstones/SDX55M/ -r -1 --partition_path /dev/block/bootdevice/by-name/ -s 21:/vendor/firmware_mnt/image/sdx55m/sbl1.mbn -s 37:/vendor/firmware_mnt/image/sdx55m/multi_image.mbn -s 38:/vendor/firmware_mnt/image/sdx55m/xbl_config.elf -s 36:/vendor/firmware_mnt/image/sdx55m/multi_image_qti.mbn -s 41:/vendor/firmware_mnt/image/sdx55m/devcfg.mbn -s 25:/vendor/firmware_mnt/image/sdx55m/tz.mbn -s 23:/vendor/firmware_mnt/image/sdx55m/aop.mbn -s 8:/vendor/firmware_mnt/image/sdx55m/qdsp6sw.mbn -s 6:/vendor/firmware_mnt/image/sdx55m/apps.mbn -s 16:/dev/block/bootdevice/by-name/mdm1m9kefs1 -s 17:/dev/block/bootdevice/by-name/mdm1m9kefs2 -s 20:/dev/block/bootdevice/by-name/mdm1m9kefs3 -s 29:/vendor/firmware_mnt/image/sdx55m/acdb.mbn -s 34:/dev/block/bootdevice/by-name/mdmddr -s 40:/vendor/firmware_mnt/image/sdx55m/apdp.mbn -s 33:/vendor/firmware_mnt/image/sdx55m/hyp.mbn -s 42:/vendor/firmware_mnt/image/sdx55m/sec.elf -a 9:mdmddr '
12-09 07:57:46.465  4580  4580 E kickstart: ERROR: function: main:135 KICKSTART CALLED LIKE THIS: '-o -p /dev/mhi_0306_02.01.00_pipe_2 -w /data/vendor/tombstones/SDX55M/ -r -1 --partition_path /dev/block/bootdevice/by-name/ -s 21:/vendor/firmware_mnt/image/sdx55m/sbl1.mbn -s 37:/vendor/firmware_mnt/image/sdx55m/multi_image.mbn -s 38:/vendor/firmware_mnt/image/sdx55m/xbl_config.elf -s 36:/vendor/firmware_mnt/image/sdx55m/multi_image_qti.mbn -s 41:/vendor/firmware_mnt/image/sdx55m/devcfg.mbn -s 25:/vendor/firmware_mnt/image/sdx55m/tz.mbn -s 23:/vendor/firmware_mnt/image/sdx55m/aop.mbn -s 8:/vendor/firmware_mnt/image/sdx55m/qdsp6sw.mbn -s 6:/vendor/firmware_mnt/image/sdx55m/apps.mbn -s 16:/dev/block/bootdevice/by-name/mdm1m9kefs1 -s 17:/dev/block/bootdevice/by-name/mdm1m9kefs2 -s 20:/dev/block/bootdevice/by-name/mdm1m9kefs3 -s 29:/vendor/firmware_mnt/image/sdx55m/acdb.mbn -s 34:/dev/block/bootdevice/by-name/mdmddr -s 40:/vendor/firmware_mnt/image/sdx55m/apdp.mbn -s 33:/vendor/firmware_mnt/image/sdx55m/hyp.mbn -s 42:/vendor/firmware_mnt/image/sdx55m/sec.e

[Thaodan]

Oh wrong file sec

[Thaodan]

logcat_modem_crash_edo.1.log

[jerpelea]

adb logcat | grep kickstart adb logcat | grep mdm_helper

shows normal behaviour

[Thaodan]

Is it normal that ks is ran twice? logcat_modem_crash_edo.2.log

[Thaodan]

The modem goes off at some point if I don't read it wrong:

[   55.061045] HTB: quantum of class 10001 is big. Consider r2q change.
[   55.085300] HTB: quantum of class 10010 is big. Consider r2q change.
[   55.107167] HTB: quantum of class 10020 is big. Consider r2q change.
[   59.714975] rpmh_rsc_send_data: 9 callbacks suppressed
[   59.714979] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[   59.769596] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[   59.800507] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[   59.809526] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[   59.932528] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[   59.950595] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[   59.955064] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[   59.959733] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[   60.193559] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[   60.237676] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[   60.917227] logd: logdr: UID=0 GID=0 PID=7634 b tail=0 logMask=99 pid=0 start=0ns timeout=0ns
[   61.387676] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[   61.391657] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 158 but ignore this function
[   61.391661] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:7210
[   61.401876] healthd: battery l=75 v=4059 t=35.0 h=2 st=2 c=182617 fc=3999000 cc=0 chg=u
[   61.674462] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = ip6tnl0
[   61.691603] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = sit0
[   61.709574] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = ip6_vti0
[   61.715554] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = ip_vti0
[   61.721702] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = lo
[   74.491363] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[   74.495340] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 137 but ignore this function
[   74.495344] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:7212
[   74.503228] healthd: battery l=75 v=4062 t=35.0 h=2 st=2 c=180663 fc=3999000 cc=0 chg=u
[   79.069507] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[   81.391934] healthd: battery l=75 v=4072 t=34.7 h=2 st=2 c=306152 fc=3999000 cc=0 chg=u
[   82.101963] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[   82.206392] i2c_geni 984000.i2c: i2c error :-107
[   82.206520] pn544_dev_write : i2c_master_send returned -107
[   82.212022] Entering OFF state from 0
[   82.212025] AOD mode OFF
[   82.242945] pn544_dev_ioctl :enter cmd = 1074063617, arg = 0
[   82.242949] pn544_dev_ioctl power off
[   82.242957] pn544_dev_ioctl :exit cmd = 1074063617, arg = 0
[   82.351262] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x42208
[   82.351279] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x42208
[   82.351294] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x42208
[   82.351308] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x42208
[   82.351323] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x42208
[   82.351337] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x42208
[   82.351369] @@@@ panel power off @@@@
[   84.949903] incell_power_lock: Lock is invalid during power off
[   84.949908] sec_ts 5-0048: [sec_input] power lock failed ret:-1
[   84.949954] sec_ts 5-0048: [sec_input] failed to lock power
[   84.950018] incell_power_unlock: Power state already unlocked
[   84.950019] sec_ts 5-0048: [sec_input] power lock failed ret:-3
[   84.950054] sec_ts 5-0048: [sec_input] failed to unlock power
[   87.595363] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[   87.599649] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 112 but ignore this function
[   87.599653] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:7215
[   87.607315] healthd: battery l=75 v=4082 t=34.7 h=2 st=2 c=430175 fc=3999000 cc=0 chg=u
[   95.189904] incell_power_lock: Lock is invalid during power off
[   95.189910] sec_ts 5-0048: [sec_input] power lock failed ret:-1
[   95.189980] sec_ts 5-0048: [sec_input] failed to lock power
[   95.190016] incell_power_unlock: Power state already unlocked
[   95.190017] sec_ts 5-0048: [sec_input] power lock failed ret:-3
[   95.190076] sec_ts 5-0048: [sec_input] failed to unlock power
[  100.700490] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[  100.704468] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 84 but ignore this function
[  100.704471] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:7219
[  100.712886] healthd: battery l=75 v=4084 t=34.5 h=2 st=2 c=421386 fc=3999000 cc=0 chg=u
[  103.430231] boot log copy done
[  105.429895] incell_power_lock: Lock is invalid during power off
[  105.429901] sec_ts 5-0048: [sec_input] power lock failed ret:-1
[  105.429973] sec_ts 5-0048: [sec_input] failed to lock power
[  105.430012] incell_power_unlock: Power state already unlocked
[  105.430013] sec_ts 5-0048: [sec_input] power lock failed ret:-3
[  105.430074] sec_ts 5-0048: [sec_input] failed to unlock power
[  113.761970] [drm:dsi_display_set_mode] [msm-dsi-info]: mdp_transfer_time_us=5925 us
[  113.761978] [drm:dsi_display_set_mode] [msm-dsi-info]: hactive= 1096,vactive= 2560,fps=60
[  113.762029] [drm:dsi_ctrl_isr_configure] [msm-dsi-info]: dsi-ctrl-0: IRQ 545 registered
[  113.779016] @@@@ panel power on @@@@
[  113.804882] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[  113.809042] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 60 but ignore this function
[  113.809047] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:7223
[  113.820078] healthd: battery l=75 v=4079 t=34.5 h=2 st=2 c=300292 fc=3999000 cc=0 chg=u
[  113.941856] [drm:dsi_pwr_panel_regulator_mode_set] *ERROR* [msm-dsi-error]: Regulator ibb was not found
[  113.941993] [drm:dsi_pwr_panel_regulator_mode_set] *ERROR* [msm-dsi-error]: Regulator lab was not found
[  113.942545] somc_panel_color_manager: somc_panel_pcc_setup (868): PCC already applied
[  114.078540] pn544_dev_ioctl :enter cmd = 1074063617, arg = 0
[  114.078546] pn544_dev_ioctl power off
[  114.078559] pn544_dev_ioctl :exit cmd = 1074063617, arg = 0
[  114.088836] pn544_dev_ioctl :enter cmd = 1074063617, arg = 1
[  114.088842] pn544_dev_ioctl power on
[  114.088852] pn544_dev_ioctl :exit cmd = 1074063617, arg = 1
[  114.089918] i2c_geni 984000.i2c: i2c error :-107
[  114.090000] pn544_dev_write : i2c_master_send returned -107
[  124.180385] i2c_geni 984000.i2c: i2c error :-107
[  124.180528] pn544_dev_write : i2c_master_send returned -107
[  124.194421] Entering OFF state from 0
[  124.194448] AOD mode OFF
[  124.216409] pn544_dev_ioctl :enter cmd = 1074063617, arg = 0
[  124.216413] pn544_dev_ioctl power off
[  124.216423] pn544_dev_ioctl :exit cmd = 1074063617, arg = 0
[  124.331990] @@@@ panel power off @@@@
[  125.909904] incell_power_lock: Lock is invalid during power off
[  125.909909] sec_ts 5-0048: [sec_input] power lock failed ret:-1
[  125.909954] sec_ts 5-0048: [sec_input] failed to lock power
[  125.910016] incell_power_unlock: Power state already unlocked
[  125.910017] sec_ts 5-0048: [sec_input] power lock failed ret:-3
[  125.910050] sec_ts 5-0048: [sec_input] failed to unlock power
[  126.911540] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[  126.916121] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 47 but ignore this function
[  126.916124] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:7225
[  126.925064] healthd: battery l=75 v=4086 t=34.5 h=2 st=2 c=423339 fc=3999000 cc=0 chg=u
[  133.464416] pm8150b_charger: usb_source_change_irq_handler: APSD_STATUS = 0x11
[  133.464572] pm8150b_charger: smblib_handle_apsd_done: IRQ: apsd-done rising; SDP detected
[  133.464574] pm8150b_charger: smblib_handle_hvdcp_detect_done: IRQ: hvdcp-detect-done falling
[  133.464577] pm8150b_charger: smblib_handle_hvdcp_check_timeout: IRQ: smblib_handle_hvdcp_check_timeout falling
[  133.464579] pm8150b_charger: smblib_handle_sdp_enumeration_done: IRQ: sdp-enumeration-done rising
[  133.464581] pm8150b_charger: smblib_handle_slow_plugin_timeout: IRQ: slow-plugin-timeout falling
[  133.464610] pm8150b_charger: usb_source_change_irq_handler: APSD_STATUS = 0x11
[  133.471053] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 36 but ignore this function
[  133.471058] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:7227
[  133.476528] healthd: battery l=75 v=4087 t=34.2 h=2 st=2 c=422363 fc=3999000 cc=0 chg=u
[  133.480794] healthd: battery l=75 v=4087 t=34.2 h=2 st=2 c=422363 fc=3999000 cc=0 chg=u
[  136.150087] incell_power_lock: Lock is invalid during power off
[  136.150092] sec_ts 5-0048: [sec_input] power lock failed ret:-1
[  136.150163] sec_ts 5-0048: [sec_input] failed to lock power
[  136.150200] incell_power_unlock: Power state already unlocked
[  136.150201] sec_ts 5-0048: [sec_input] power lock failed ret:-3
[  136.150262] sec_ts 5-0048: [sec_input] failed to unlock power
[  140.017348] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[  140.021335] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 23 but ignore this function
[  140.021338] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:7229
[  140.031277] healthd: battery l=75 v=4089 t=34.2 h=2 st=2 c=430663 fc=3999000 cc=0 chg=u
[  141.391472] healthd: battery l=75 v=4089 t=34.2 h=2 st=2 c=426757 fc=3999000 cc=0 chg=u
[  146.389891] incell_power_lock: Lock is invalid during power off
[  146.389896] sec_ts 5-0048: [sec_input] power lock failed ret:-1
[  146.389942] sec_ts 5-0048: [sec_input] failed to lock power
[  146.390005] incell_power_unlock: Power state already unlocked
[  146.390006] sec_ts 5-0048: [sec_input] power lock failed ret:-3
[  146.390039] sec_ts 5-0048: [sec_input] failed to unlock power
[  148.415773] ext-mdm soc:qcom,mdm0: mdm_errfatal: mdm sent errfatal interrupt
[  148.416053] [E][mhi_control_error] mhi:esoc0 sfr: 0xffffff800c57d000
[  150.711682] ext-mdm soc:qcom,mdm0: unexpected reset external modem
[  150.711739] unable to queue event for SDX55M
[  150.711848] subsys-restart: subsystem_restart_dev(): Restart sequence requested for esoc0, restart_level = RELATED.
[  150.713919] subsys-restart: subsystem_shutdown(): [kworker/u17:15:4445]: Shutting down esoc0
[  150.718885] sysmon-qmi: ssctl_del_server: Connection lost between QMI handle and esoc0's SSCTL service
[  150.735396] Core dump to |/usr/sbin/rich-core-dumper --pid=5515 --signal=31 --name=ims_rtp_daemon disabled
[  150.738107] ------------[ cut here ]------------
[  150.738188] workqueue: WQ_MEM_RECLAIM mhi_w:mhi_pm_st_worker is flushing !WQ_MEM_RECLAIM events_highpri:flush_backlog
[  150.738201] WARNING: CPU: 0 PID: 4446 at kernel/workqueue.c:2530 check_flush_dependency+0xd4/0x120
[  150.738293] Modules linked in:
[  150.738300] CPU: 0 PID: 4446 Comm: kworker/u17:16 Tainted: G S      W         4.19.188-g4114118d4df6-dirty #8
[  150.738301] Hardware name: Sony Mobile Communications. PDX-203(KONA) (DT)
[  150.738306] Workqueue: mhi_w mhi_pm_st_worker
[  150.738310] pstate: 60c00085 (nZCv daIf +PAN +UAO)
[  150.738314] pc : check_flush_dependency+0xd4/0x120
[  150.738317] lr : check_flush_dependency+0xd4/0x120
[  150.738318] sp : ffffff8021273800
[  150.738319] x29: ffffff8021273800 x28: ffffff801087d0d8 
[  150.738322] x27: ffffff801087cf60 x26: ffffff9a6dab0870 
[  150.738325] x25: 0000000000000003 x24: fffffff07994cc80 
[  150.738328] x23: 0000000000000001 x22: fffffff079951f00 
[  150.738330] x21: ffffff9a6c1670b0 x20: fffffff04a9cbc00 
[  150.738333] x19: ffffffef0681dc00 x18: ffffffffffffffff 
[  150.738336] x17: 0000000000000000 x16: ffffff9a6dd209a0 
[  150.738338] x15: ffffff9aedd22797 x14: 4345525f4d454d5f 
[  150.738341] x13: 51572120676e6968 x12: 73756c6620736920 
[  150.738343] x11: 72656b726f775f74 x10: 735f6d705f69686d 
[  150.738346] x9 : 3a775f69686d204d x8 : 0000000000000080 
[  150.738349] x7 : 73756c663a697270 x6 : ffffff9a6dd222b9 
[  150.738351] x5 : 0000000000000000 x4 : 0000000000000000 
[  150.738353] x3 : ffffffffffffffff x2 : 0000000000000000 
[  150.738356] x1 : 0000000000000000 x0 : ffffff9a6da0d000 
[  150.738359] Call trace:
[  150.738363]  check_flush_dependency+0xd4/0x120
[  150.738366]  __flush_work+0xa8/0x260
[  150.738368]  flush_work+0x10/0x20
[  150.738373]  rollback_registered_many+0x1d0/0x5dc
[  150.738375]  rollback_registered+0x60/0xb0
[  150.738377]  unregister_netdevice_queue+0x90/0x120
[  150.738380]  unregister_netdev+0x20/0x30
[  150.738382]  mhi_netdev_remove+0x50/0x1fc
[  150.738385]  mhi_driver_remove+0x17c/0x390
[  150.738392]  __device_release_driver+0x16c/0x20c
[  150.738395]  device_release_driver+0x28/0x40
[  150.738398]  bus_remove_device+0x118/0x124
[  150.738401]  device_del+0x168/0x3c4
[  150.738404]  mhi_destroy_device+0x58/0x90
[  150.738406]  device_for_each_child+0x5c/0xb0
[  150.738409]  mhi_pm_st_worker+0x55c/0xbe0
[  150.738412]  process_one_work+0x1a4/0x41c
[  150.738414]  worker_thread+0x200/0x410
[  150.738417]  kthread+0x134/0x160
[  150.738422]  ret_from_fork+0x10/0x24
[  150.738424] ---[ end trace 13deb5f4995a630e ]---
[  150.739453] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_mhi0
[  150.739457] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister
[  150.749806] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data0
[  150.751081] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data1
[  150.752146] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data2
[  150.753729] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data3
[  150.755334] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data4
[  150.756868] rmnet_shs deinit rmnet_data5 going down 
[  150.756917] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data5
[  150.809075] rmnet_ctl driver removed
[  150.810685] msm_pcie_oper_conf: Read of RC2 1:0x00 + 0x0060[4] is all FFs
[  150.811041] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.811147] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.811209] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.811310] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.811372] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.811519] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.811624] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.811683] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.811783] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.811987] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  150.812047] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.812141] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.812198] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.812295] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.812532] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  150.812606] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.812699] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  150.812792] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.812845] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.813353] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  150.813415] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.813625] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  150.813721] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.813775] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  150.813869] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  150.824471] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  150.926554] msm_pcie_disable: PCIe: Assert the reset of endpoint of RC2.

Full log: dmesg.edo.modem_crash.2.log

[Thaodan]

Same issue booting aosp, image just build yesterday. The manifest is here: https://github.com/mer-hybris/android/blob/sony-aosp-11/localbuild.xml

Log: logcat_modem_crash_edo.3.log

[Thaodan]

Flashed stock 58.1.A.5.395 today everything works fine. After flashing AOSP rhe issue is the same. My build is Sony/aosp_xqat51/pdx203:11/RQ3A.211001.001/builder12101553:user/test-keys.

[Thaodan]

Is there maybe something missing from the copyleft kernel @jerpelea @bartcubbins ?

[bartcubbins]

Unfortunately I have no experience with external modems, as well as time to investigate this bug until I finish porting Kumano, Seine and Tama platforms to the 4.19 kernel. I'm really sorry

[Thaodan]

It looks better now however '/dev/mhi_0306_02.01.00_pipe_2' still disappears.

libmdmimgload: '/dev/mhi_0306_02.01.00_pipe_2' was not found

[Thaodan]

[  128.085402] rmnet_shs deinit rmnet_data5 going down 
[  128.085420] rmnet_perf_config_notify_cb(): rmnet_perf netdevice unregister, name = rmnet_data5
[  128.085837] droid-hal-init: Service 'vendor.imsdatadaemon' (pid 4240) exited with status 0
[  128.085844] droid-hal-init: Sending signal 9 to service 'vendor.imsdatadaemon' (pid 4240) process group... HYBRIS: killing PID instead of process group.
[  128.086191] droid-hal-init: Service 'vendor.ims_rtp_daemon' (pid 5631) received signal 31
[  128.086425] droid-hal-init: starting service 'vendor.ims_rtp_daemon'...
[  128.087879] droid-hal-init: starting service 'vendor.imsdatadaemon'...
[  128.087942] droid-hal-init: Created socket '/dev/socket/ims_datad', mode 660, user 1000, group 1001
[  128.125288] rmnet_ctl driver removed
[  128.125512] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.125595] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.125659] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.125696] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.125762] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.125823] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.125857] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.125916] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.125950] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.126009] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.126121] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  128.126154] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.126213] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.126271] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.126304] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.126402] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  128.126434] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.126492] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  128.126553] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.126585] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.126763] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  128.126824] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.126891] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  128.126949] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.126981] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  128.127054] msm_pcie_oper_conf: PCIe: RC2 wr fail, link down - bus 1 devfn 0
[  128.141122] msm_pcie_oper_conf: PCIe: RC2 rd fail, link down - bus 1 devfn 0
[  128.244066] msm_pcie_disable: PCIe: Assert the reset of endpoint of RC2.
[  131.298078] subsys-restart: subsystem_powerup(): [kworker/u17:24:4446]: Powering up esoc0
[  131.456094] msm_pcie_enable: PCIe: Assert the reset of endpoint of RC2.
[  131.459441] msm_pcie_enable: PCIe: RC2: PCIE20_PARF_INT_ALL_MASK: 0x7f80d202
[  131.461644] pcie_phy_init: PCIe RC2 PHY is ready!
[  131.471667] msm_pcie_enable: PCIe: Release the reset of endpoint of RC2.
[  131.488094] msm_pcie_link_train: PCIe RC2 link initialized
[  131.488368] mhi 0002:01:00.0: BAR 0: assigned [mem 0x64300000-0x64300fff 64bit]
[  131.488405] mhi 0002:01:00.0: enabling device (0000 -> 0002)
[  131.489199] [E][mhi_init_pci_dev] Failed to enable MSI, ret:-28
[  132.640724] FG: fg_gen4_somc_jeita_step_charge_work: [Charging] BSOC:8632 MSOC:8992 RTEMP:307 IBATT:155mA VBATT:4198mV VCELL:4198mV Target FCC:2850mA FV:4400mV
[  134.923045] cs35l41 1-0040: Timout waiting for DSP to set mbox cmd
[  134.923495] cs35l41 1-0040: Failed to set mailbox(cmd: 2, sts: 1)
[  134.923591] cs35l41 1-0040: ASoC: POST_PMU: L Main AMP event failed: -42
[  134.923691] __afe_port_start: port id: 0x1018
[  134.923705] afe_find_cal_topo_id_by_port: port id: 0x1018, dev_acdb_id: 15
[  134.923709] afe_find_cal_topo_id_by_port: top_id:112fc acdb_id:15 afe_port_id:0x1018
[  134.923713] afe_get_cal_topology_id: port_id = 0x1018 acdb_id = 15 topology_id = 0x112fc cal_type_index=8 ret=0
[  134.923976] afe_send_port_topology_id: AFE set topology id 0x112fc  enable for port 0x1018 ret 0
[  134.923980] send_afe_cal_type: cal_index is 0
[  134.923983] send_afe_cal_type: dev_acdb_id[53] is 15
[  134.923986] afe_find_cal: cal_index 0 port_id 0x1018 port_index 53
[  134.923989] afe_find_cal: acdb_id 15 dev_acdb_id 15 sample_rate 48000 afe_sample_rates 48000
[  134.923991] afe_find_cal: cal block is a match, size is 0
[  134.923992] send_afe_cal_type: Sending cal_index cal 0
[  134.923994] send_afe_cal_type: No cal sent for cal_index 0, port_id = 0x1018! ret -22
[  134.924331] afe_send_hw_delay: port_id 0x1018 rate 48000 delay_usec 474 status 0
[  140.817782] afe_close: port_id = 0x1018
[  141.010461] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[  141.014901] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: -19 but ignore this function
[  141.014906] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:8631
[  141.021542] healthd: battery l=90 v=4191 t=30.7 h=2 st=2 c=-213378 fc=3999000 cc=0 chg=u
[  141.778539] healthd: battery l=90 v=4191 t=30.7 h=2 st=2 c=-213378 fc=3999000 cc=0 chg=u
[  142.279447] cs35l41 1-0040: Timout waiting for DSP to set mbox cmd
[  142.279906] cs35l41 1-0040: Failed to set mailbox(cmd: 2, sts: 1)
[  142.280003] cs35l41 1-0040: ASoC: POST_PMU: L Main AMP event failed: -42
[  142.280198] __afe_port_start: port id: 0x1018
[  142.280212] afe_find_cal_topo_id_by_port: port id: 0x1018, dev_acdb_id: 15
[  142.280217] afe_find_cal_topo_id_by_port: top_id:112fc acdb_id:15 afe_port_id:0x1018
[  142.280221] afe_get_cal_topology_id: port_id = 0x1018 acdb_id = 15 topology_id = 0x112fc cal_type_index=8 ret=0
[  142.280488] afe_send_port_topology_id: AFE set topology id 0x112fc  enable for port 0x1018 ret 0
[  142.280491] send_afe_cal_type: cal_index is 0
[  142.280495] send_afe_cal_type: dev_acdb_id[53] is 15
[  142.280498] afe_find_cal: cal_index 0 port_id 0x1018 port_index 53
[  142.280501] afe_find_cal: acdb_id 15 dev_acdb_id 15 sample_rate 48000 afe_sample_rates 48000
[  142.280503] afe_find_cal: cal block is a match, size is 0
[  142.280506] send_afe_cal_type: Sending cal_index cal 0
[  142.280508] send_afe_cal_type: No cal sent for cal_index 0, port_id = 0x1018! ret -22
[  142.280891] afe_send_hw_delay: port_id 0x1018 rate 48000 delay_usec 474 status 0
[  147.904565] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[  148.054022] afe_close: port_id = 0x1018
[  154.111100] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[  154.115361] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: -2 but ignore this function
[  154.115364] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:8628
[  154.124126] healthd: battery l=90 v=4170 t=31.0 h=2 st=2 c=-486327 fc=3999000 cc=0 chg=u
[  157.946457] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 3 but ignore this function
[  157.946463] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:8627
[  157.954394] healthd: battery l=90 v=4177 t=31.0 h=2 st=2 c=-367675 fc=3999000 cc=0 chg=u
[  166.422982] rpmh_rsc_send_data: 5 callbacks suppressed
[  166.422985] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  166.436186] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  167.211355] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[  167.216456] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 11 but ignore this function
[  167.216460] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:8626
[  167.225095] healthd: battery l=90 v=4188 t=31.2 h=2 st=2 c=-158203 fc=3999000 cc=0 chg=u
[  167.683972] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  167.688360] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  167.692496] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  167.701670] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  167.754670] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  167.759330] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  167.768355] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  167.772577] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  178.816404] rpmh_rsc_send_data: 9 callbacks suppressed
[  178.816408] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  180.311305] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[  180.315695] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 21 but ignore this function
[  180.315700] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:8624
[  180.327636] healthd: battery l=90 v=4187 t=31.5 h=2 st=2 c=-180175 fc=3999000 cc=0 chg=u

[  193.412291] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[  193.417139] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 29 but ignore this function
[  193.417143] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:8623
[  193.425867] healthd: battery l=90 v=4187 t=31.5 h=2 st=2 c=-176757 fc=3999000 cc=0 chg=u
[  200.014413] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  201.780687] healthd: battery l=90 v=4186 t=31.7 h=2 st=2 c=-176757 fc=3999000 cc=0 chg=u
[  206.513658] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[  206.518135] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 38 but ignore this function
[  206.518139] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:8621
[  206.527985] healthd: battery l=90 v=4186 t=31.7 h=2 st=2 c=-173828 fc=3999000 cc=0 chg=u
[  208.010629] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30080
[  212.212526] i2c_geni 984000.i2c: i2c error :-107
[  212.212597] pn544_dev_write : i2c_master_send returned -107
[  212.222220] Entering OFF state from 0
[  212.222223] AOD mode OFF
[  212.251675] pn544_dev_ioctl :enter cmd = 1074063617, arg = 0
[  212.251679] pn544_dev_ioctl power off
[  212.251687] pn544_dev_ioctl :exit cmd = 1074063617, arg = 0
[  212.360224] @@@@ panel power off @@@@
[  218.080382] incell_power_lock: Lock is invalid during power off
[  218.080394] sec_ts 5-0048: [sec_input] power lock failed ret:-1
[  218.080530] sec_ts 5-0048: [sec_input] failed to lock power
[  218.080595] incell_power_unlock: Power state already unlocked
[  218.080598] sec_ts 5-0048: [sec_input] power lock failed ret:-3
[  218.080712] sec_ts 5-0048: [sec_input] failed to unlock power
[  219.615094] pm8150b_charger: somc_aicl_irq_handler: IRQ: aicl-done
[  219.619326] FG: fg_gen4_cl_ok_to_begin: IBAT_FLT thr: 100 val: 41 but ignore this function
[  219.619329] ALG: cap_learning_update: [SOMC CL][OFF] charge_status:1 bsoc_cp:8620
[  219.632467] healthd: battery l=90 v=4196 t=31.7 h=2 st=2 c=-29296 fc=3999000 cc=0 chg=u
[  228.320199] incell_power_lock: Lock is invalid during power off
[  228.320210] sec_ts 5-0048: [sec_input] power lock failed ret:-1
[  228.320341] sec_ts 5-0048: [sec_input] failed to lock power
[  228.320528] incell_power_unlock: Power state already unlocked
[  228.320532] sec_ts 5-0048: [sec_input] power lock failed ret:-3
[  228.320646] sec_ts 5-0048: [sec_input] failed to unlock power
[  231.605479] unable to queue event for SDX55M
[  231.605661] mdm-4x esoc0: booting failed
[  231.605797] Unable to handle kernel NULL pointer dereference at virtual address 0000000000000004
[  231.605911] Mem abort info:
[  231.605972]   ESR = 0x96000005
[  231.606034]   Exception class = DABT (current EL), IL = 32 bits
[  231.606196]   SET = 0, FnV = 0
[  231.606256]   EA = 0, S1PTW = 0
[  231.606315] Data abort info:
[  231.606374]   ISV = 0, ISS = 0x00000005
[  231.606480]   CM = 0, WnR = 0

[Thaodan]

After applying https://github.com/sonyxperiadev/kernel/pull/2471 the esoc can restart fine. However the original issue that the modem restarts is still there.

If I read the issue right Xperia 1 III could be also affected when the 5.4.y stable commit https://github.com/gregkh/linux/commit/a85f3e7cb717057b7fff66addd645c774403927e is applied.

dmesg.edo.modem.restart.log

[Thaodan]

Closing, all done here.