AI智能摘要
问题现象 高通平台项目,工厂老化遇到一例卡开机logo的问题,连接usb没有端口,连接串口也毫无log打印,遂强制触发fulldump,抓取dump分析。 初步分析 从kernel log来看,当时机器已经开机了50000多秒: [57514.034099][ T728] [CM]:charger
此摘要由AI分析文章内容生成,仅供参考。

问题现象

高通平台项目,工厂老化遇到一例卡开机logo的问题,连接usb没有端口,连接串口也毫无log打印,遂强制触发fulldump,抓取dump分析。

初步分析

从kernel log来看,当时机器已经开机了50000多秒:

[57514.034099][  T728] [CM]:charger_manager_charger_type_detect:ch = 0, authenticate = 0
[57514.757979][  T192] [CM]:handle_recharge_eea:handle_recharge_eea: temp:250, uisoc:95, volt:4280, curr:171000
[57514.757983][  T192] [CM]:handle_recharge_eea:handle_recharge_eea:full=0, full_cnt=0, recharge_cnt=0
[57515.238037][ T1540]  fg_get_device_id(3975): revision_id = 0x3

但是基本都是充电模块打印的一些和卡logo无关的信息。

怀疑可能是死锁/关键进程卡死等问题导致,于是进一步查看当时的进程信息,很快就定位到了可疑的进程:

Process: init, [affinity: 0xff] cpu: 5 pid: 1 start: 0xffffff8002dc2400
=====================================================
    Task name: init             [affinity: 0xff] pid:      1 tgid:      1 cpu: 5 prio: 120 start: 0xffffff8002dc2400
    state: 0x2[D] exit_state: 0x0 stack base: 0xffffffc008058000
    Last_enqueued_ts:       5.769644496 Last_sleep_ts:       5.769656996
    Stack:
    [<ffffffdfa688fc50>] __switch_to+0x164
    [<ffffffdfa7a00ea4>] __schedule+0x530
    [<ffffffdfa7a01368>] schedule+0xc4
    [<ffffffdfa7a01940>] io_schedule+0x3c
    [<ffffffdfa7a09c58>] wait_on_page_bit_common+0x2e8
    [<ffffffdfa7a09e64>] __lock_page+0x5c
    [<ffffffdfa6e60de8>] __get_node_page.llvm.15847610073229764972+0xd4
    [<ffffffdfa6e24830>] do_read_inode+0x5c
    [<ffffffdfa6e24398>] f2fs_iget+0xe0
    [<ffffffdfa6e27bcc>] f2fs_lookup.b99782f4484836f60b0518856aeae55d+0xf8
    [<ffffffdfa6c4d304>] __lookup_slow+0xd8
    [<ffffffdfa6c4d698>] lookup_slow+0x44
    [<ffffffdfa6c54ef0>] walk_component+0x15c
    [<ffffffdfa6c539d0>] link_path_walk+0x264
    [<ffffffdfa6c4c78c>] path_lookupat+0x6c
    [<ffffffdfa6c4c62c>] filename_lookup+0xcc
    [<ffffffdfa6c4d8f8>] user_path_at_empty+0x50
    [<ffffffdfa6c3961c>] do_faccessat+0xb0
    [<ffffffdfa6c36c00>] __arm64_sys_faccessat+0x28
    [<ffffffdfa68bbc94>] invoke_syscall+0x60
    [<ffffffdfa68bbbc4>] el0_svc_common.llvm.10050182446765365532+0xb8
    [<ffffffdfa68bba9c>] do_el0_svc+0x28
    [<ffffffdfa79b7954>] el0_svc+0x24
    [<ffffffdfa79b78cc>] el0t_64_sync_handler+0x88
    [<ffffffdfa681164c>] el0t_64_sync+0x1b8

init进程从五秒多开始就一直处于D状态,init处于异常状态,系统肯定是起不起来的!!

结合堆栈信息,发现当时是在尝试获取PG_locked但是获取失败,使用io_schedule()尝试等待IO结束但依然失败,只能schedule()调度出去。

结合其他task的堆栈,没能定位到为什么init进程会获取PG_locked失败,遂请求平台支援。

平台分析

平台很快就定位到了是UFS异常!UFS从开机五秒之后就没有触发过中断。

怀疑是UFS单体有异常,此问题后续交给UFS同事进行跟进。

相关结构

我们来看一下ufs_stats的相关结构体:

struct ufs_stats

/**
 * struct ufs_stats - keeps usage/err statistics
 * @last_intr_status: record the last interrupt status.
 * @last_intr_ts: record the last interrupt timestamp.
 * @hibern8_exit_cnt: Counter to keep track of number of exits,
 *                reset this after link-startup.
 * @last_hibern8_exit_tstamp: Set time after the hibern8 exit.
 *                Clear after the first successful command completion.
 */
struct ufs_stats {
        u32 last_intr_status;
        ktime_t last_intr_ts;//参考注释,记录了最后一次中断的时间戳

        u32 hibern8_exit_cnt;
        ktime_t last_hibern8_exit_tstamp;
        struct ufs_event_hist event[UFS_EVT_CNT];
};

ktime_t

由注释可知,ktime_t的单位是 纳秒,1 秒 = 10⁹ 纳秒

因此5xxxxxxxxx(一共9个x)其实就是5秒多。

/* Nanosecond scalar representation for kernel time values */
typedef s64        ktime_t;

如何得到ufs_stats?

那么我们如何得到ufs_stats呢?

首先查看ufs_stats和其他结构体之间的关系,发现ufs_stats内嵌于ufs_hba中

struct ufs_hba {
        void __iomem *mmio_base;

         .........

        u32 saved_uic_err;
        struct ufs_stats ufs_stats;
        bool force_reset;
        bool force_pmc;
        bool silence_err_logs;

        ..............
};

那么接下来该如何获取ufs_hba呢?

阅读代码,进一步发现,ufs_hba是作为ufs device的driver_data的。

那接下来需要确定ufs驱动所对应的device

我们查看ufs驱动对应的源码文件,发现ufs驱动是一个platform驱动

static struct platform_driver ufs_qcom_pltform = {
        .probe        = ufs_qcom_probe,
        .remove        = ufs_qcom_remove,
        .shutdown = ufs_qcom_shutdown,
        .driver        = {
                .name        = "ufshcd-qcom",
                .pm        = &ufs_qcom_pm_ops,
                .of_match_table = of_match_ptr(ufs_qcom_of_match),
                .acpi_match_table = ACPI_PTR(ufs_qcom_acpi_match),
        },
};
module_platform_driver(ufs_qcom_pltform);

接下来看一下它的of_match匹配表:

static const struct of_device_id ufs_qcom_of_match[] = {
        { .compatible = "qcom,ufshc"},
        {},
};
MODULE_DEVICE_TABLE(of, ufs_qcom_of_match);

compatible用于匹配设备驱动和设备树中的硬件节点

进一步在代码中搜索"qcom,ufshc",在设备树中找到唯一相关的一个节点:

        ufshc_mem: ufshc@4804000 {
                compatible = "qcom,ufshc";
                reg = <0x4804000 0x3000>, <0x4810000 0x8000>;
                reg-names = "ufs_mem", "ufs_ice";
                interrupts = <GIC_SPI 356 IRQ_TYPE_LEVEL_HIGH>;
                phys = <&ufsphy_mem>;
                phy-names = "ufsphy";

具体的设备名,通常和在设备树中的节点相关。

在dump解析出来的device.txt找到对应的设备:

v.v (struct device)  name                     bus_name         driver_data                       
0xffffff8003ed5c10   4804000.ufshc           platform         0xffffff8035d8c9e8    

name和设备树中的吻合,且也是对应于platform总线,说明就是这个。

device.txt中已经给出了driver_data即ufs_hba的地址,那么直接使用T32获取:

进一步找到ufs_stat:

last_intr_ts是指上一次ufs发生中断的时间,last_intr_ts = 5540306508,单位是ns